CCIE-V Understanding Basic MGCP Egress Call Setup

For the past couple of months I have been diligently preparing myself for a successful CCIE-V lab. One of the key factors in successfully navigating this exam is your ability to quickly troubleshoot a problem and, sometimes, provide information to the proctor about how you came to your conclusions. 

Unfortunately, you can't say things like "well, I know the codec is G711 because the phone told me so (double "?")" nor can you use explanations such as: "based on the annunciator message, I conclude that the call is failing because it is Unallocated/Unassigned". You actually need to show definitive proof to back up your conclusion. So, you need to dissect traces or debugs and demonstrate that you understand them fluently. 

I have been collecting notes on trace dissection as I study and I figured that I should try to integrate studying with my blog a little more than I have to date. So, this may be ugly but I am going to start with a basic MGCP call and using "debug mgcp packet" to identify the key phases of call setup, media initiation, and call termination.

Background

We want to capture an egress call from an IP phone to a PSTN station whereby the call traverses one of our MGCP gateways. We are only interested in identifying the key phases of the call setup, media initiation, and call termination. The call we are dissecting is "healthy". Meaning, there isn't an issue to troubleshoot. You can't really troubleshoot anything if you don't know what a "normal" call should look like, right?

The players:

• Cisco IP Phone (I am using a 7965 running SCCP, but it doesn't matter what you use)
• Cisco 2800 ISR running MGCP
• A PSTN station ("911 Operator")
• CUCM (7.0)

The script:

1. Cisco IP phone goes off hook and dials: 911
2. CUCM uses MGCP to initiate call setup to Cisco 2800
3. Cisco 2800 relays ISDN messages to PSTN
4. PSTN station answers the call
5. The call is terminated

The Walkthrough

We are using the following commands on our Cisco 2800 ISR:

• debug mgcp packet
• debug isdn q931

When you do this live, the output of these debug options will be mingled together. I am going to clean that up a bit. Just keep in mind that if you have to use multiple debug commands (or trace flags in CCM trace) then you will want to hone your "detangling" skills.

Call Setup

The IP phone has gone off hook and has dialed "911". The first message we see is a MGCP CRCX (create connection) message from CUCM (10.3.120.11).

Sep  5 13:41:24.089: MGCP Packet received from 10.3.120.11:2427--->
CRCX 55 S0/SU0/DS1-0/8@HQ-RTR MGCP 0.1
C: D0000000021ab858000000F500000003
X: 8
L: p:20, a:PCMU, s:off, t:b8, fxr/fx:t38
M: recvonly
R: D/[0-9ABCD*#]
Q: process,loop
<---

Let's do some dissection:

• We can clearly see that the MGCP packet is being sent from 10.3.120.11 and the endpoint on HQ-RTR is identified
• The "C:" is a globally unique conference ID for this connection
• "X:" identifies an ID that CUCM will use when it communicates information about this call. So, a follow up RQNT message about this call would have "X: 8"
• The "L:" value line is pretty handy, it tells us about the codec we are using:
• (p:20) sampling rate is 20ms
• (a:PCMU) the codec is G.711 u-law
• (s:off) VAD is BAD (therefore, we have turned it off)
• (t:b8) type of service
• "M: recvonly" instructs the MGCP device to set up its side of the connection, the call isn't bi-directional yet because we haven't answered on the other end
• "R:" instructs the MGCP device to load the "digit map" package and the valid digits are identified (0-9ABCD*#)

The MGCP gateway responds to CUCM (10.3.120.11) with a "200" OK message.

Sep  5 13:41:24.097: MGCP Packet sent to 10.3.120.11:2427--->
200 55 OK
I: A

v=0
c=IN IP4 10.3.110.1
m=audio 19128 RTP/AVP 0 100
a=rtpmap:100 X-NSE/8000
a=fmtp:100 192-194,200-202
a=X-sqn:0
a=X-cap: 1 audio RTP/AVP 100
a=X-cpar: a=rtpmap:100 X-NSE/8000
a=X-cpar: a=fmtp:100 192-194,200-202
a=X-cap: 2 image udptl t38
<---

Some of the more interesting values in this response message:

• The gateway instructs the CUCM to use the local call ID of "I=A" when the CUCM needs to reference this call.
• The gateway identifies the source IP address (10.3.110.1) that should be used for media streams from the IP phone.
• The "m=" line identifies the UDP port that should be used for RTP media (19128).
• The jumble of "a=" lines is part of capabilities exchange, "a=X-sqn:0" says that the endpoint supports G.711 u-law

In tandem to the MGCP packets, we will also see the gateway start signaling the call to the PSTN. Our calling party number is "5552001" and our called party is "911". You can also see plan and type information, as well as calling name IE (if we were sending it, which we are not).

The PSTN responds with a "call proceeding" message and relays the call alerting state.

Sep  5 13:41:24.101: ISDN Se0/0/0:23 Q931: TX -> SETUP pd = 8  callref = 0x0003 
        Bearer Capability i = 0x8090A2 
                Standard = CCITT 
                Transfer Capability = Speech  
                Transfer Mode = Circuit 
                Transfer Rate = 64 kbit/s 
        Channel ID i = 0xA98388 
                Exclusive, Channel 8 
        Calling Party Number i = 0x0081, '5552001' 
                Plan:Unknown, Type:Unknown 
        Called Party Number i = 0x80, '911' 
                Plan:Unknown, Type:Unknown
Sep  5 13:41:24.133: ISDN Se0/0/0:23 Q931: RX <- CALL_PROC pd = 8  callref = 0x8003 
        Channel ID i = 0xA98388 
                Exclusive, Channel 8
Sep  5 13:41:24.145: ISDN Se0/0/0:23 Q931: RX <- ALERTING pd = 8  callref = 0x8003 
        Progress Ind i = 0x8188 - In-band info or appropriate now available

Media Path Established

Once the call is in alerting state, the CUCM will send a MDCX (modify connection) message to the MGCP gateway. You can see in the following example that the local call ID ("I: A") and the CUCM call ID ("X: 8") is used so the MGCP call is clearly identifiable. The codec information ("L: ") and digit map information is basically the same. What is notably different is the "M:" line, which now says: "sendrecv".

CUCM is instructing the gateway to transition from receive only to send/receive mode. We also see that the target endpoint for the media stream from the MGCP device is 10.3.200.128 on UDP port 27664.
 

Sep  5 13:41:24.177: MGCP Packet received from 10.3.120.11:2427--->
MDCX 56 S0/SU0/DS1-0/8@HQ-RTR MGCP 0.1
C: D0000000021ab858000000F500000003
I: A
X: 8
L: p:20, a:PCMU, s:off, t:b8, fxr/fx:t38
M: sendrecv
R: D/[0-9ABCD*#], FXR/t38
S: 
Q: process,loop

v=0
o=- 10 0 IN EPN S0/SU0/DS1-0/8@HQ-RTR
s=Cisco SDP 0
t=0 0
m=audio 27664 RTP/AVP 0
c=IN IP4 10.3.200.128
a=X-sqn:0
a=X-cap:1 image udptl t38
<---

The MGCP gateway responds with a 200 OK:

Sep  5 13:41:24.181: MGCP Packet sent to 10.3.120.11:2427--->
200 56 OK
<---

The above sequence of events is establishing the media path information. Which is to say that the MGCP now has the information it needs to send the audio stream to the remote party when the call is connected. Shortly after the media information exchange, the ISDN party answers the call (ISDN Q.931 debug output):

Sep  5 13:41:26.721: ISDN Se0/0/0:23 Q931: RX <- CONNECT pd = 8  callref = 0x8003
Sep  5 13:41:26.725: ISDN Se0/0/0:23 Q931: TX -> CONNECT_ACK pd = 8  callref = 0x0003

The MGCP gateway receives notification that the call is connected and immediately sends a connection acknowledgement. At this point, the local IP phone and the remote PSTN party ("911 operator") have a full-duplex talk path.

Call Termination

In our example, the local IP phone initiates call termination by going on hook. Therefore, the first message we see is a MDCX (modify connection) from the CUCM to the MGCP device. Notice that the "M:" line instructs the MGCP device to transition to receive only (recvonly).

Sep  5 13:41:36.577: MGCP Packet received from 10.3.120.11:2427--->
MDCX 57 S0/SU0/DS1-0/8@HQ-RTR MGCP 0.1
C: D0000000021ab858000000F500000003
I: A
X: 8
M: recvonly
R: D/[0-9ABCD*#]
Q: process,loop
<---

The MGCP device should respond with a "200 OK" message and then we will see ISDN call clearing messages sent to the PSTN.

Sep  5 13:41:36.585: ISDN Se0/0/0:23 Q931: TX -> DISCONNECT pd = 8  callref = 0x0003 
        Cause i = 0x8290 - Normal call clearing
Sep  5 13:41:36.593: ISDN Se0/0/0:23 Q931: RX <- RELEASE pd = 8  callref = 0x8003

We are almost done here. The CUCM must send a DLCX (delete connection) message to the MGCP device to complete the call termination process. The MGCP device will respond with a 250 OK message. In the 250 OK message there is a "P:" line which provides call statistic information:

• Packets Sent (PS)
• Octets Sent (OS)
• Packets Received (PR)
• Octets Received (OR)
• Packet Loss (PL)
• Jitter (JI)
• Latency (LA)

Sep  5 13:41:36.593: MGCP Packet received from 10.3.120.11:2427--->
DLCX 58 S0/SU0/DS1-0/8@HQ-RTR MGCP 0.1
C: D0000000021ab858000000F500000003
I: A
X: 8
S: 
<---

Sep  5 13:41:36.617: MGCP Packet sent to 10.3.120.11:2427--->
250 58 OK
P: PS=620, OS=99200, PR=620, OR=99200, PL=0, JI=0, LA=0
<---

The last message we see here is the MGCP gateway sending a "Release Complete" to the PSTN. Since the CUCM deleted the connection, it is "released".

Sep  5 13:41:36.621: ISDN Se0/0/0:23 Q931: TX -> RELEASE_COMP pd = 8  callref = 0x0003

Using this Information

The first step to being able to clearly and concisely answer any troubleshooting questions is to understand what a normal call looks like. You have to understand the key fields in the various MGCP and ISDN messages. This way, when a call fails to establish for whatever reason, you can identify both where things are "healthy" (or normal) and where something fails. Not only that, you need to use the cryptic fields to support you assertion as to "why" a call failed.

---

Thanks for reading. If you have time, post a comment!