[cisco-voip] Weird ISDN disconnection issue when using H323 and CUCM 8.0.2C
Ki Wi
kiwi.voice at gmail.com
Tue Jul 27 23:24:50 EDT 2010
I finally fixed the problem already. The traces (sdi /sdl) in the
callmanager didn't help much. It doesn't complain lack of resources such as
MTP at all.
Just happened that I finally happen to browse into route list and I
discovered that I left the callmanager group as default. Able to make 1 x
outgoing call makes me thinks that my route list is correct. After changing
it to something else, it works. =(
However, i still don't understand why by leaving it as default (which means
only 1 x publisher) cause such problem. There's no device pool (so no
MGLP/no region/no location,etc) associated to this CMG. Is it going to be
the root cause?
Cheers,
Ki Wi
On Wed, Jul 28, 2010 at 6:08 AM, Peter Slow <peter.slow at gmail.com> wrote:
> i recant my previous statement. the weird TCS message you are seeing
> will go away. I make no guarantee that that is the cause of your
> one-call-at-a-time problem, but fixing that error isa really good
> place to start, since its an obvious error with a call you're having
> trouble with. once you fix that, if it's still occurring, take a
> second look at the debugs.
>
> -Peter
>
> On Tue, Jul 27, 2010 at 6:05 PM, Peter Slow <peter.slow at gmail.com> wrote:
> > the non standard TCS messae is most often en when the TCS you receive
> > contains every capabiltiy in the universe due to your call using
> > dial-peer 0 as it goes throgh the gateway. this theory also explains
> > why you only have the issue in one direction. take one of the voip
> > dial pers you have being used for calls from the PSTN to the CUCM, and
> > put
> > incoming called-number .
> > ...on it. my hyphen might be misplaced, but that will probably fix your
> issue.
> >
> > -Peter
> >
> > On Tue, Jul 27, 2010 at 11:27 AM, Ki Wi <kiwi.voice at gmail.com> wrote:
> >> At the CCM trace, i noticed the following
> >>
> >> 23:02:13.487 |RouteListControl::idle_CcSetupReq - RouteList(RL_SG),
> >> numberSetup=1 numberMember=0
> >> vmEnabled=0|1,100,49,1.1475986^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:13.487 |RouteListControl::idle_CcSetupReq - RouteList(RL_SG),
> >> RouteListCdrc::create CI = 18217036 BRANCH = 0
> >> mIsEmccHunt=0|1,100,49,1.1475986^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:14.860 |ConnectionManager - wait_AuDisconnectRequest ERROR:NO
> ENTRY
> >> FOUND IN
> >>
> TABLE,CI(18217035,18217036),dcType=1,IFCreated(0,0),PID(0-0,0-0),IFHandling(0,0),MCNode(0,0)|1,100,49,1.1475986^10.0.13.5^SEP0019DXXXXXXX
> >> 23:02:14.860 |MatrixControl:updatePartyMediaCoordinatorNodeId: party1
> >> videoCapable=0, party 2
> >> videocapable=0|1,100,49,1.1475986^10.0.13.5^SEP0019DXXXXXXX
> >> 23:02:16.066 |LineControl TEST DEBUGS: Number of entries in CallTable is
> =
> >> 1
> >> |1,100,49,1.1475989^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:17.768 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,49,1.1475991^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:17.768 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,49,1.1475991^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:17.768 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,49,1.1475991^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:17.769 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,49,1.1475991^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:17.769 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,49,1.1475991^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:19.316 |LineControl TEST DEBUGS: Number of entries in CallTable is
> =
> >> 1
> >> |1,100,49,1.1475997^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:19.317 |MediaManager(3037)::wait_AuDisconnectRequest,
> >> mCleanupPreallocatedMTP=0|1,100,49,1.1475997^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:19.335 |MatrixControl:updatePartyMediaCoordinatorNodeId: party1
> >> videoCapable=0, party 2 videocapable=0|1,100,16,2355.22^10.0.13.5^Port
> 62671
> >> 23:02:19.335 |ViprUtils: Number has no +, not a valid E164
> >> [99XXXXXX9]|1,100,16,2355.22^10.0.13.5^Port 62671
> >> 23:02:21.005 |RouteListControl::idle_CcSetupReq - RouteList(RL_SG),
> >> numberSetup=0 numberMember=0
> >> vmEnabled=0|1,100,49,1.1476001^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:21.005 |RouteListControl::idle_CcSetupReq - RouteList(RL_SG),
> >> RouteListCdrc::create CI = 18217038 BRANCH = 0
> >> mIsEmccHunt=0|1,100,49,1.1476001^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:22.227 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,211,4201.1^*^*
> >> 23:02:22.227 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,211,4201.1^*^*
> >> 23:02:22.227 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,211,4201.1^*^*
> >> 23:02:22.227 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,211,4201.1^*^*
> >> 23:02:22.227 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,211,4201.1^*^*
> >> 23:02:26.238 |TranslateAndTransport(2359)::wait_SdlCloseInd - ERROR:
> H245
> >> signaling connection aborted!!!|1,100,16,2359.7^10.0.13.5^Port 65014
> >> 23:02:26.238 |H225Cdpc(0003107)::call_received7_TcpStopSessionInd: H225
> Tcp
> >> session terminated
> abnormally|1,100,49,1.1476001^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:26.239 |MediaManager(3038)::wait_AuDisconnectRequest,
> >> mCleanupPreallocatedMTP=0|1,100,49,1.1476001^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:26.240 |MatrixControl:updatePartyMediaCoordinatorNodeId: party1
> >> videoCapable=0, party 2
> >> videocapable=0|1,100,49,1.1476001^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:29.374 |LineControl TEST DEBUGS: Number of entries in CallTable is
> =
> >> 1
> >> |1,100,49,1.1476014^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:30.317 |RouteListControl::idle_CcSetupReq - RouteList(RL_SG),
> >> numberSetup=0 numberMember=0
> >> vmEnabled=0|1,100,49,1.1476015^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:30.317 |RouteListControl::idle_CcSetupReq - RouteList(RL_SG),
> >> RouteListCdrc::create CI = 18217040 BRANCH = 0
> >> mIsEmccHunt=0|1,100,49,1.1476015^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:31.624 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,211,4202.1^*^*
> >> 23:02:31.624 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,211,4202.1^*^*
> >> 23:02:31.624 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,211,4202.1^*^*
> >> 23:02:31.624 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,211,4202.1^*^*
> >> 23:02:31.624 |H245Handler(1)::There is an error in decoding H.245 TCS
> >> Non-Standard data.|1,100,211,4202.1^*^*
> >> 23:02:39.148 |MediaManager(3039)::wait_AuDisconnectRequest,
> >> mCleanupPreallocatedMTP=0|1,100,49,1.1476031^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:39.158 |MatrixControl:updatePartyMediaCoordinatorNodeId: party1
> >> videoCapable=0, party 2 videocapable=0|1,100,16,2360.11^10.0.13.5^Port
> 11939
> >> 23:02:39.158 |MediaResourceManager::sendAllocationResourceErr - ERROR -
> no
> >> MOH device configured|1,100,16,2360.11^10.0.13.5^Port 11939
> >> 23:02:40.126 |RouteListControl::idle_CcSetupReq - RouteList(RL_SG),
> >> numberSetup=1 numberMember=0
> >> vmEnabled=0|1,100,49,1.1476036^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:40.126 |RouteListControl::idle_CcSetupReq - RouteList(RL_SG),
> >> RouteListCdrc::create CI = 18217043 BRANCH = 0
> >> mIsEmccHunt=0|1,100,49,1.1476036^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:45.090 |H225Cdpc(0003109)::call_received7_TcpStopSessionInd: H225
> Tcp
> >> session terminated
> abnormally|1,100,49,1.1476036^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:45.090 |TranslateAndTransport(2361)::wait_SdlCloseInd - ERROR:
> H245
> >> signaling connection aborted!!!|1,100,16,2361.7^10.0.13.5^Port 18637
> >> 23:02:45.091 |MediaManager(3040)::wait_AuDisconnectRequest,
> >> mCleanupPreallocatedMTP=0|1,100,49,1.1476036^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:45.092 |MatrixControl:updatePartyMediaCoordinatorNodeId: party1
> >> videoCapable=0, party 2
> >> videocapable=0|1,100,49,1.1476036^10.0.12.125^SEP0019DXXXXXXX
> >> 23:02:46.500 |LineControl TEST DEBUGS: Number of entries in CallTable is
> =
> >> 1
> >> |1,100,49,1.1476043^10.0.12.125^SEP0019DXXXXXXX
> >> 23:04:16.908 |ViprUtils: Number has no +, not a valid E164
> >> [99XXXXXX9]|1,100,16,2360.11^10.0.13.5^Port 11939
> >> 23:04:16.909 |MatrixControl:updatePartyMediaCoordinatorNodeId: party1
> >> videoCapable=0, party 2 videocapable=0|1,100,16,2360.11^10.0.13.5^Port
> 11939
> >> 23:04:16.910 |LineControl TEST DEBUGS: Number of entries in CallTable is
> =
> >> 0
> >>
> >>
> >> This is the first time I met such error.
> >>
> >> Over at debug h245 asn1 and h225 asn1
> >>
> >> ul 27 12:42:32.905: H225.0 OUTGOING ENCODE BUFFER::=
> >>
> 280032C0060008914A00042800B500001240013C050100000A00180A2AF90080B8DF6E3ED4E1C4070090010A000C7D05800100010010A801003A0140B50000123360010100011E2C1E0284841C269E8100036774640000001B4350472C0D0A50524E2C6973646E2A2C2C4E4554352A2C0D0A0D0A224204677464011B4350472C0D0A50524E2C6973646E2A2C2C4E4554352A2C0D0A0D0A
> >> Jul 27 12:42:32.905:
> >> Jul 27 12:42:32.921: //19868/80B8DF6E0700/CCAPI/cc_api_call_alert:
> >> Interface=0x14641E2C, Progress Indication=NULL(0), Signal
> Indication=NOT
> >> PRESENT(255)
> >> Jul 27 12:42:32.921: //19868/80B8DF6E0700/CCAPI/cc_api_call_alert:
> >> Call Entry(Retry Count=0, Responsed=TRUE)
> >> Jul 27 12:42:32.921: //19867/80B8DF6E0700/CCAPI/ccCallAlert:
> >> Progress Indication=INBAND(8), Signal Indication=NOT PRESENT(255)
> >> Jul 27 12:42:32.921: //19867/80B8DF6E0700/CCAPI/ccCallAlert:
> >> Call Entry(Responsed=TRUE, Alert Sent=TRUE)
> >> Jul 27 12:42:32.921:
> >> //19868/80B8DF6E0700/CCAPI/cc_api_get_called_ccm_detected:
> >> CallInfo(ccm detected=0)
> >> Jul 27 12:42:32.921: //19867/80B8DF6E0700/CCAPI/cc_api_get_delay_xport:
> >> CallInfo(delay xport=FALSE)
> >> Jul 27 12:42:36.377: H225 NONSTD OUTGOING PDU ::=
> >>
> >> value H323_UU_NonStdInfo ::=
> >> {
> >> version 1
> >> protoParam qsigNonStdInfo :
> >> {
> >> iei 28
> >> rawMesg '1C269E8100036774640000001B41434D2C0D0A50...'H
> >> }
> >> progIndParam progIndIEinfo :
> >> {
> >> progIndIE '00000008'H
> >> }
> >> }
> >>
> >>
> >>
> >> Jul 27 12:42:36.377: H225 NONSTD OUTGOING ENCODE BUFFER::=
> >>
> E0010100011C281C269E8100036774640000001B41434D2C0D0A50524E2C6973646E2A2C2C4E4554352A2C0D0A0D0A18800006000400000008
> >> Jul 27 12:42:36.377:
> >> Jul 27 12:42:36.377: H225.0 OUTGOING PDU ::=
> >>
> >> value H323_UserInformation ::=
> >> {
> >> h323-uu-pdu
> >> {
> >> h323-message-body releaseComplete :
> >>
> >>
> >>
> >>
> >>
> >> On Tue, Jul 27, 2010 at 6:38 PM, Jason Aarons (US)
> >> <jason.aarons at us.didata.com> wrote:
> >>>
> >>> Your transmitting the disconnect to telco, problem is higher up the
> >>> stack. Debug voip ccapi inout, debug h225 asn, etc, pull a CCM Trace
> and
> >>> use Triple Combo Tool.
> >>>
> >>>
> >>>
> >>> I’d consider switching from H323 to SIP, traces are much easier to
> read.
> >>>
> >>>
> >>>
> >>> I tend to suspect your requiring a MTP resource for some reason which
> >>> isn’t available, or could be in H245 codec failure, or your having a
> rtp
> >>> audio stream problem, etc.
> >>>
> >>>
> >>>
> >>> From: cisco-voip-bounces at puck.nether.net
> >>> [mailto:cisco-voip-bounces at puck.nether.net] On Behalf Of Ki Wi
> >>> Sent: Tuesday, July 27, 2010 12:36 AM
> >>> To: Cisco VoIP List
> >>> Subject: [cisco-voip] Weird ISDN disconnection issue when using H323
> and
> >>> CUCM 8.0.2C
> >>>
> >>>
> >>>
> >>> The setup is based on cucm 8.0.2c & 2 x vg (at 2 different site) using
> >>> h.323
> >>>
> >>> 1 vg is based on 15.0(1)M1
> >>> 1 vg is based on 15.1(2)T
> >>>
> >>> Both of them display the same characteristic when doing outbound call
> to
> >>> PSTN while inbound call is not affected by this issue.
> >>>
> >>> When 1 x isdn channel is used(taken) up, others cannot make outbound
> call
> >>> at all.
> >>>
> >>> When in SRST mode, both vg with their individual ISDN connection can
> >>> receive inbound and outbound call from PSTN normally.
> >>>
> >>> Currently my interim solution is to allow all the phones to stay in
> SRST
> >>> while trying to find out the root cause.
> >>> I'm able to replicate the problem by allowing my CIPC to connect to the
> >>> callmanager and make 2 x outgoing call to my mobile. First one will go
> >>> through while second call will get disconnected for some unknown
> reason. I
> >>> noticed about this temporary failure issue but what bug me is nothing
> goes
> >>> wrong when so many phones are in SRST mode right now.
> >>>
> >>> I have attached the debug isdn q931 configuration.
> >>>
> >>> Jul 27 04:20:00.271: ISDN Se0/0/0:15 Q931: Applying typeplan for
> sw-type
> >>> 0x12 is 0x0 0x0, Calling num 62XXXX50
> >>> Jul 27 04:20:00.271: ISDN Se0/0/0:15 Q931: Sending SETUP callref =
> 0x0C32
> >>> callID = 0x8BB3 switch = primary-net5 interface = User
> >>> Jul 27 04:20:00.271: ISDN Se0/0/0:15 Q931: TX -> SETUP pd = 8 callref
> =
> >>> 0x0C32
> >>> Bearer Capability i = 0x8090A3
> >>> Standard = CCITT
> >>> Transfer Capability = Speech
> >>> Transfer Mode = Circuit
> >>> Transfer Rate = 64 kbit/s
> >>> Channel ID i = 0xA9839E
> >>> Exclusive, Channel 30
> >>> Progress Ind i = 0x8183 - Origination address is non-ISDN
> >>> Calling Party Number i = 0x0081, '62XXXX50'
> >>> Plan:Unknown, Type:Unknown
> >>> Called Party Number i = 0x80, '9XXXXXX9'
> >>> Plan:Unknown, Type:Unknown
> >>> Jul 27 04:20:00.599: ISDN Se0/0/0:15 Q931: RX <- CALL_PROC pd = 8
> callref
> >>> = 0x8C32
> >>> Channel ID i = 0xA9839E
> >>> Exclusive, Channel 30
> >>> Jul 27 04:20:02.079: ISDN Se0/0/0:15 Q931: RX <- PROGRESS pd = 8
> callref
> >>> = 0x8C32
> >>> Progress Ind i = 0x8482 - Destination address is non-ISDN
> >>> Progress Ind i = 0x8488 - In-band info or appropriate now
> >>> available
> >>> Jul 27 04:20:04.051: ISDN Se0/0/0:15 Q931: RX <- PROGRESS pd = 8
> callref
> >>> = 0x8C32
> >>> Progress Ind i = 0x8484 - Call has returned to the ISDN
> >>> Jul 27 04:20:04.139: ISDN Se0/0/0:15 Q931: RX <- ALERTING pd = 8
> callref
> >>> = 0x8C32
> >>> Jul 27 04:20:05.419: ISDN Se0/0/0:15 Q931: RX <- CONNECT pd = 8
> callref =
> >>> 0x8C32
> >>> Date/Time i = 0x0A071B0C14
> >>> Date (dd-mm-yr) = 10-07-27
> >>> Time (hr:mnt:sec) = 12:20:24
> >>> Jul 27 04:20:05.423: %ISDN-6-CONNECT: Interface Serial0/0/0:29 is now
> >>> connected to 9XXXXXX9 N/A
> >>> Jul 27 04:20:05.423: ISDN Se0/0/0:15 Q931: TX -> CONNECT_ACK pd = 8
> >>> callref = 0x0C32
> >>> Jul 27 04:20:16.959: ISDN Se0/0/0:15 Q931: Applying typeplan for
> sw-type
> >>> 0x12 is 0x0 0x0, Calling num 62XXXX50
> >>> Jul 27 04:20:16.959: ISDN Se0/0/0:15 Q931: Sending SETUP callref =
> 0x0C33
> >>> callID = 0x8BB4 switch = primary-net5 interface = User
> >>> Jul 27 04:20:16.959: ISDN Se0/0/0:15 Q931: TX -> SETUP pd = 8 callref
> =
> >>> 0x0C33
> >>> Bearer Capability i = 0x8090A3
> >>> Standard = CCITT
> >>> Transfer Capability = Speech
> >>> Transfer Mode = Circuit
> >>> Transfer Rate = 64 kbit/s
> >>> Channel ID i = 0xA9839D
> >>> Exclusive, Channel 29
> >>> Progress Ind i = 0x8183 - Origination address is non-ISDN
> >>> Calling Party Number i = 0x0081, '62XXXX50'
> >>> Plan:Unknown, Type:Unknown
> >>> Called Party Number i = 0x80, '9XXXXXX9'
> >>> Plan:Unknown, Type:Unknown
> >>> Jul 27 04:20:17.287: ISDN Se0/0/0:15 Q931: RX <- CALL_PROC pd = 8
> callref
> >>> = 0x8C33
> >>> Channel ID i = 0xA9839D
> >>> Exclusive, Channel 29
> >>> Jul 27 04:20:18.779: ISDN Se0/0/0:15 Q931: RX <- PROGRESS pd = 8
> callref
> >>> = 0x8C33
> >>> Progress Ind i = 0x8482 - Destination address is non-ISDN
> >>> Progress Ind i = 0x8488 - In-band info or appropriate now
> >>> available
> >>> Jul 27 04:20:19.039: ISDN Se0/0/0:15 Q931: RX <- ALERTING pd = 8
> callref
> >>> = 0x8C33
> >>> Progress Ind i = 0x8484 - Call has returned to the ISDN
> >>> Jul 27 04:20:22.791: ISDN Se0/0/0:15 Q931: TX -> DISCONNECT pd = 8
> >>> callref = 0x0C33
> >>> Cause i = 0x80A9 - Temporary failure
> >>> Jul 27 04:20:22.927: ISDN Se0/0/0:15 Q931: RX <- RELEASE pd = 8
> callref =
> >>> 0x8C33
> >>>
> >>>
> >>>
> >>>
> >>> ________________________________
> >>>
> >>> Disclaimer: This e-mail communication and any attachments may contain
> >>> confidential and privileged information and is for use by the
> designated
> >>> addressee(s) named above only. If you are not the intended addressee,
> you
> >>> are hereby notified that you have received this communication in error
> and
> >>> that any use or reproduction of this email or its contents is strictly
> >>> prohibited and may be unlawful. If you have received this communication
> in
> >>> error, please notify us immediately by replying to this message and
> deleting
> >>> it from your computer. Thank you.
> >>
> >> _______________________________________________
> >> cisco-voip mailing list
> >> cisco-voip at puck.nether.net
> >> https://puck.nether.net/mailman/listinfo/cisco-voip
> >>
> >>
> >
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20100728/beb90903/attachment.html>
More information about the cisco-voip
mailing list