[cisco-voip] Weird ISDN disconnection issue when using H323 and CUCM 8.0.2C
Peter Slow
peter.slow at gmail.com
Tue Jul 27 18:08:59 EDT 2010
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
>>
>>
>
More information about the cisco-voip
mailing list