[cisco-voip] MGCP to PSTN - 0x80A9 - Temporary failure?

Wed Feb 3 09:51:51 EST 2010

Normally a temp failure coming from CUCM means a device involved in the call unregistered.  With MGCP gateways this is most common when you have MGCP messages getting lost between CUCM and the router.  CUCM will retransmit a message 3 times before unregistering the gateway.

In this case you have a traceback followed by the gateway sending a DLCX (delete connection) message to the CUCM, which ends up with CUCM tearing down the call.  

I'd recommend putting your traceback (and the other required info) into the output interpreter at https://www.cisco.com/cgi-bin/Support/OutputInterpreter/home.pl.  

-Ryan

On Feb 3, 2010, at 8:29 AM, Stephen Greszczyszyn wrote:

Hi there,

I'm working on a lab scenario where I'm making calls from CUCM7 via an
IOS MGCP gateway out to another router simulating the PSTN.  The call
connects OK, but after about 1 minute - 2 minutes, the call drops.  I
have tried the same test through another H.323 gateway and the call
stays up fine.  Running 12.4(24)T2 on the MGCP gateway.  Here is the
information:

MGCP gateway:
Feb  3 11:53:33.851: ISDN Se0/1/0:15 Q931: TX -> DISCONNECT pd = 8
callref = 0x0007
      Cause i = 0x80A9 - Temporary failure

PSTN:
*Feb  3 11:59:57.011: ISDN Se0/3/0:15 Q931: RX <- DISCONNECT pd = 8
callref = 0x0007
      Cause i = 0x80A9 - Temporary failure
*Feb  3 11:59:57.015: %ISDN-6-DISCONNECT: Interface Serial0/3/0:0
disconnected from +16178631002 , call lasted 72 seconds

I did some searching on this list and there were some references to
faulty DSPs.  Mine seem to look OK?

MGCP:
br1#sh voice dsp group all
DSP groups on slot 0:
dsp 1:
State: UP, firmware: 24.3.2
Max signal/voice channel: 16/16
Max credits: 240
num_of_sig_chnls_allocated: 8
Transcoding channels allocated: 0
Group: FLEX_GROUP_VOICE, complexity: FLEX
  Shared credits: 225, reserved credits: 0
  Signaling channels allocated: 8
  Voice channels allocated: 1
  Credits used: 15
  Voice channels:
    Ch01: voice port: 0/1/0:15.1, codec: g711ulaw, credits allocated: 15

PSTN:
WAN_PSTN#sh voice dsp group all
DSP groups on slot 0:
dsp 1:
State: UP, firmware: 24.3.2
Max signal/voice channel: 16/16
Max credits: 240
num_of_sig_chnls_allocated: 16
Transcoding channels allocated: 0
Group: FLEX_GROUP_VOICE, complexity: FLEX
  Shared credits: 225, reserved credits: 0
  Signaling channels allocated: 16
  Voice channels allocated: 1
  Credits used: 15
  Voice channels:
    Ch01: voice port: 0/3/0:15.1, codec: g711ulaw, credits allocated: 15

I also get some weird stuff around the time of call failure when I
enable MGCP debugging:

debug mgcp errors
debug mgcp packet

It seems as though my MGCP gateway tells CUCM to drop the call and
also sends the disconnect to the PSTN:

MGCP:
Feb  3 13:09:00.557: ISDN Se0/1/0:15 Q921: User TX -> INFO sapi=0
tei=0, ns=14 nr=15
Feb  3 13:09:00.557: ISDN Se0/1/0:15 Q931: DISCONNECT pd = 8  callref = 0x0003
      Cause i = 0x80A9 - Temporary failure

PSTN:
*Feb  3 13:15:23.583: ISDN Se0/3/0:15 Q921: Net RX <- INFO sapi=0
tei=0, ns=14 nr=15
*Feb  3 13:15:23.583: ISDN Se0/3/0:15 Q931: DISCONNECT pd = 8  callref = 0x0003
      Cause i = 0x80A9 - Temporary failure

(Previous call traces - MGCP debug)

Feb  3 12:52:45.713: Following traceback is for INFO ONLY. -Traceback=
0x40F3126Cz 0x40F5BA6Cz 0x40F4296Cz 0x40F3ABC4z 0x40F333D4z
0x40EEED44z 0x40EF43F0z 0x435D69D8z 0x435D69BCz
Feb  3 12:52:45.717: MGCP Packet sent to 10.10.210.11:2427--->
DLCX 205358175 S0/SU1/DS1-0/1 at br1.proctorlabs.com MGCP 0.1
C: D000000002a512c9000000F500000002
I: 3
P: PS=5000, OS=800000, PR=4978, OR=796480, PL=22, JI=7, LA=0
E: 502
<---

Feb  3 12:52:45.725: MGCP Packet received from 10.10.210.11:2427--->
200 205358175
<---

Feb  3 12:52:45.725:
//-1/xxxxxxxxxxxx/MGCP/mgcp_mp_get_not_entity(830):[lvl=2]Invalid
parameter (pkt 0x4A428FE0 pkt->mgcp_parm_lines 0x00000000)
Feb  3 12:52:45.733: ISDN Se0/1/0:15 Q931: TX -> DISCONNECT pd = 8
callref = 0x0002
      Cause i = 0x80A9 - Temporary failure
Feb  3 12:52:45.745: ISDN Se0/1/0:15 Q931: RX <- RELEASE pd = 8
callref = 0x8002
Feb  3 12:52:45.757: ISDN Se0/1/0:15 Q931: TX -> RELEASE_COMP pd = 8
callref = 0x0002
Feb  3 12:53:04.977: MGCP Packet sent to 10.10.210.11:2427--->
NTFY 205358176 *@br1.proctorlabs.com MGCP 0.1
X: 0
O:
<---

In the CUCM traces, it isn't clear to me why the call is being dumped:

02/03/2010 12:52:45.690 CCM|MGCPHandler received msg from: 10.10.110.2
DLCX 205358175 S0/SU1/DS1-0/1 at br1.proctorlabs.com MGCP 0.1
C: D000000002a512c9000000F500000002
I: 3
P: PS=5000, OS=800000, PR=4978, OR=796480, PL=22, JI=7, LA=0
E: 502
|<CLID::StandAloneCluster><NID::10.10.210.11><CT::2,100,132,1.837><IP::10.10.110.2><DEV::><LVL::Significant><MASK::2000>
02/03/2010 12:52:45.690
CCM|<CLID::StandAloneCluster><NID::10.10.210.11><CT::2,100,132,1.837><MN::MGCPEndPoint><MV::S0/SU1/DS1-0/1 at br1.proctorlabs.com><DEV::><LVL::All><MASK::ffff>
02/03/2010 12:52:45.691 CCM|MGCPHandler send msg SUCCESSFULLY to: 10.10.110.2
200 205358175
|<CLID::StandAloneCluster><NID::10.10.210.11><CT::2,100,132,1.837><IP::10.10.110.2><DEV::S0/SU1 at br1.proctorlabs.com><LVL::Significant><MASK::2000>
02/03/2010 12:52:45.692 CCM|ConnectionManager -
wait_AuDisconnectRequest(44372680,44372681),disconnectType(1),
IFHandling(0,0)|<CLID::StandAloneCluster><NID::10.10.210.11><CT::2,100,132,1.837><IP::10.10.110.2><DEV::S0/SU1 at br1.proctorlabs.com><LVL::Arbitrary><MASK::0800>
02/03/2010 12:52:45.692 CCM|ConnectionManager -
storeMediaInfo(44372680): EXISTING ENTRY DISCOVERED,
size=2|<CLID::StandAloneCluster><NID::10.10.210.11><CT::2,100,132,1.837><IP::10.10.110.2><DEV::S0/SU1 at br1.proctorlabs.com><LVL::Arbitrary><MASK::0800>
02/03/2010 12:52:45.692 CCM|ConnectionManager -
storeMediaInfo(44372681): EXISTING ENTRY DISCOVERED,
size=2|<CLID::StandAloneCluster><NID::10.10.210.11><CT::2,100,132,1.837><IP::10.10.110.2><DEV::S0/SU1 at br1.proctorlabs.com><LVL::Arbitrary><MASK::0800>
02/03/2010 12:52:45.692 CCM|MediaCoordinator -
wait_AuDisconnectRequest,CI(44372680,44372681),IFCreated(1,1)|<CLID::StandAloneCluster><NID::10.10.210.11><CT::2,100,132,1.837><IP::10.10.110.2><DEV::S0/SU1 at br1.proctorlabs.com><LVL::Significant><MASK::0800>
02/03/2010 12:52:45.692 CCM|MediaCoordinator -
wait_AuDisconnectRequest - sending disconnect to
MediaManager(48)|<CLID::StandAloneCluster><NID::10.10.210.11><CT::2,100,132,1.837><IP::10.10.110.2><DEV::S0/SU1 at br1.proctorlabs.com><LVL::Significant><MASK::0800>

...

02/03/2010 12:52:45.694 CCM|MGCPpn9d - Dump portInfo table:
portInfo[00] endpoint=S0/SU1/DS1-0/1 at br1.proctorlabs.com, ci=44372681
portInfo[01] endpoint=S0/SU1/DS1-0/2 at br1.proctorlabs.com, ci=0
portInfo[02] endpoint=S0/SU1/DS1-0/3 at br1.proctorlabs.com, ci=0

...

02/03/2010 12:52:45.698 CCM|Out Message -- PriDisconnectMsg --
Protocol= PriEuroProtocol|<CLID::StandAloneCluster><NID::10.10.210.11><LVL::Significant><MASK::0040>
02/03/2010 12:52:45.698 CCM|Ie - Q931CauseIe IEData= 08 02 80 A9
|<CLID::StandAloneCluster><NID::10.10.210.11><LVL::State
Transition><MASK::0040>

Thanks for any suggestions!
_______________________________________________
cisco-voip mailing list
cisco-voip at puck.nether.net
https://puck.nether.net/mailman/listinfo/cisco-voip