[cisco-voip] H323 Voip Call Connected for 5 sec and then drops

Anthony Kouloglou akoul at dataways.gr
Fri Nov 11 10:15:14 EST 2011 

Hi all,
i really need your help before i go crazy.
I have never seen a call connected and talk (both dirextions)  for 5 
secs and then disconnect!!
I have seen calls not being able to initiate or one way audio or no 
audio but not this!!

The call flow is: A calls a destination in B

A(PBX with E1/PRI) 
--->2800-----------------voip------------>2900---->B(PBX with E1/Pri) B.

2800 discovers 2900 dial plan with ras command (gatekeeper controlled both).
I would be searching for misconfigurations in translation rules and all 
these but the call SUCCEEDS initially, so i guess it is OK.
I can see Transfer number is Null but i can't tell why.

Also, i have tried to set progress_ind setup enable 3 (in the pots 
dial-peer from 2900 to PBX (B)) but no luck!
The same problem.

Keep in mind, that i have NO access to 2800: it is a TSP with the same 
config for everyone else.

Here is the debug i got (ccapi voip and q931):

Nov 11 13:03:39.539: //-1/9C287DE9AAC7/CCAPI/cc_api_display_ie_subfields:
    cc_api_call_setup_ind_common:
    cisco-username=gw-2811 at XXX.gr
    ----- ccCallInfo IE subfields -----
    cisco-ani=2107275672
    cisco-anitype=0
    cisco-aniplan=1
    cisco-anipi=0
    cisco-anisi=0
    dest=2321049160
    cisco-desttype=0
    cisco-destplan=0
    cisco-rdie=FFFFFFFF
    cisco-rdn=
    cisco-rdntype=-1
    cisco-rdnplan=-1
    cisco-rdnpi=-1
    cisco-rdnsi=-1
    cisco-redirectreason=-1   fwd_final_type =0
    final_redirectNumber =
    hunt_group_timeout =0

Nov 11 13:03:39.539: //-1/9C287DE9AAC7/CCAPI/cc_api_call_setup_ind_common:
    Interface=0x2AF60854, Call Info(
    Calling Number=2107275672,(Calling Name=)(TON=Unknown, NPI=ISDN, 
Screening=Not Screened, Presentation=Allowed),
    Called Number=2321049160(TON=Unknown, NPI=Unknown),
    Calling Translated=FALSE, Subscriber Type Str=Unknown, 
FinalDestinationFlag=TRUE,
    Incoming Dial-peer=21, Progress Indication=ORIGINATING SIDE IS NON 
ISDN(3), Calling IE Present=TRUE,
    Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID 
Transparent=FALSE), Call Id=103
Nov 11 13:03:39.539: //-1/9C287DE9AAC7/CCAPI/ccCheckClipClir:
    In: Calling Number=2107275672(TON=Unknown, NPI=ISDN, Screening=Not 
Screened, Presentation=Allowed)
Nov 11 13:03:39.539: //-1/9C287DE9AAC7/CCAPI/ccCheckClipClir:
    Out: Calling Number=2107275672(TON=Unknown, NPI=ISDN, Screening=Not 
Screened, Presentation=Allowed)
Nov 11 13:03:39.539: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Nov 11 13:03:39.539: :cc_get_feature_vsa malloc success
Nov 11 13:03:39.539: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Nov 11 13:03:39.539:  cc_get_feature_vsa count is 1
Nov 11 13:03:39.539: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Nov 11 13:03:39.539: :FEATURE_VSA attributes are: 
feature_name:0,feature_time:836178384,feature_id:102
Nov 11 13:03:39.539: //103/9C287DE9AAC7/CCAPI/cc_api_call_setup_ind_common:
    Set Up Event Sent;
    Call Info(Calling Number=2107275672(TON=Unknown, NPI=ISDN, 
Screening=Not Screened, Presentation=Allowed),
    Called Number=2321049160(TON=Unknown, NPI=Unknown))
Nov 11 13:03:39.539: //103/9C287DE9AAC7/CCAPI/cc_process_call_setup_ind:
    Event=0x31809038
Nov 11 13:03:39.539: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
    Try with the demoted called number 2321049160
Nov 11 13:03:39.539: //103/9C287DE9AAC7/CCAPI/ccCallSetContext:
    Context=0x2A68E544
Nov 11 13:03:39.539: //103/9C287DE9AAC7/CCAPI/cc_process_call_setup_ind:
 >>>>CCAPI handed cid 103 with tag 21 to app "_ManagedAppProcess_Default"
Nov 11 13:03:39.539: //103/9C287DE9AAC7/CCAPI/ccCallProceeding:
    Progress Indication=NULL(0)
Nov 11 13:03:39.543: //103/9C287DE9AAC7/CCAPI/ccCallSetupRequest:
    Destination=, Calling IE Present=TRUE, Mode=0,
    Outgoing Dial-peer=23210491, Params=0x2A69723C, Progress 
Indication=ORIGINATING SIDE IS NON ISDN(3)
Nov 11 13:03:39.543: //103/9C287DE9AAC7/CCAPI/ccCheckClipClir:
    In: Calling Number=2107275672(TON=Unknown, NPI=ISDN, Screening=Not 
Screened, Presentation=Allowed)
Nov 11 13:03:39.543: //103/9C287DE9AAC7/CCAPI/ccCheckClipClir:
    Out: Calling Number=2107275672(TON=Unknown, NPI=ISDN, Screening=Not 
Screened, Presentation=Allowed)
Nov 11 13:03:39.543: //103/9C287DE9AAC7/CCAPI/ccCallSetupRequest:
    Destination Pattern=23210491.., Called Number=2321049160, Digit 
Strip=TRUE
Nov 11 13:03:39.543: //103/9C287DE9AAC7/CCAPI/ccCallSetupRequest:
    Calling Number=2107275672(TON=Unknown, NPI=ISDN, Screening=Not 
Screened, Presentation=Allowed),
    Called Number=2321049160(TON=Unknown, NPI=Unknown),
    Redirect Number=, Display Info=
    Account Number=gw-2811 at XXX.gr, Final Destination Flag=TRUE,
    Guid=9C287DE9-0B8B-11E1-AAC7-0013C3996140, Outgoing Dial-peer=23210491
Nov 11 13:03:39.543: //103/9C287DE9AAC7/CCAPI/cc_api_display_ie_subfields:
    ccCallSetupRequest:
    cisco-username=gw-2811 at XXX.gr
    ----- ccCallInfo IE subfields -----
    cisco-ani=2107275672
    cisco-anitype=0
    cisco-aniplan=1
    cisco-anipi=0
    cisco-anisi=0
    dest=2321049160
    cisco-desttype=0
    cisco-destplan=0
    cisco-rdie=FFFFFFFF
    cisco-rdn=
    cisco-rdntype=-1
    cisco-rdnplan=-1
    cisco-rdnpi=-1
    cisco-rdnsi=-1
    cisco-redirectreason=-1   fwd_final_type =0
    final_redirectNumber =
    hunt_group_timeout =0

Nov 11 13:03:39.543: //103/9C287DE9AAC7/CCAPI/ccIFCallSetupRequestPrivate:
    Interface=0x3183EBD8, Interface Type=6, Destination=, Mode=0x0,
    Call Params(Calling Number=2107275672,(Calling Name=)(TON=Unknown, 
NPI=ISDN, Screening=Not Screened, Presentation=Allowed),
    Called Number=2321049160(TON=Unknown, NPI=Unknown), Calling 
Translated=FALSE,
    Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing 
Dial-peer=23210491, Call Count On=FALSE,
    Source Trkgrp Route Label=, Target Trkgrp Route Label=, 
tg_label_flag=0, Application Call Id=)
Nov 11 13:03:39.543: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Nov 11 13:03:39.543: :cc_get_feature_vsa malloc success
Nov 11 13:03:39.543: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Nov 11 13:03:39.543:  cc_get_feature_vsa count is 2
Nov 11 13:03:39.543: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Nov 11 13:03:39.543: :FEATURE_VSA attributes are: 
feature_name:0,feature_time:836178832,feature_id:103
Nov 11 13:03:39.543: //104/9C287DE9AAC7/CCAPI/ccIFCallSetupRequestPrivate:
    SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1
Nov 11 13:03:39.543: //104/9C287DE9AAC7/CCAPI/ccCallSetContext:
    Context=0x2A6971EC
Nov 11 13:03:39.543: //103/9C287DE9AAC7/CCAPI/ccSaveDialpeerTag:
    Outgoing Dial-peer=23210491
Nov 11 13:03:39.547: ISDN Se0/0/0:15 Q931: Applying typeplan for sw-type 
0x12 is 0x0 0x1, Calling num 2107275672
Nov 11 13:03:39.547: ISDN Se0/0/0:15 Q931: Sending SETUP  callref = 
0x009D callID = 0x801E switch = primary-net5 interface = Network
Nov 11 13:03:39.547: ISDN Se0/0/0:15 Q931: TX -> SETUP pd = 8  callref = 
0x009D
         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
         Progress Ind i = 0x8183 - Origination address is non-ISDN
         Calling Party Number i = 0x0180, '2107275672'
                 Plan:ISDN, Type:Unknown
         Called Party Number i = 0x80, '160'
                 Plan:Unknown, Type:Unknown
Nov 11 13:03:39.683: ISDN Se0/0/0:15 Q931: RX <- SETUP_ACK pd = 8  
callref = 0x809D
Nov 11 13:03:39.859: ISDN Se0/0/0:15 Q931: RX <- CALL_PROC pd = 8  
callref = 0x809D
Nov 11 13:03:39.859: //104/9C287DE9AAC7/CCAPI/cc_api_call_proceeding:
    Interface=0x3183EBD8, Progress Indication=NULL(0)
Nov 11 13:03:39.871: ISDN Se0/0/0:15 Q931: RX <- ALERTING pd = 8  
callref = 0x809D
Nov 11 13:03:39.871: //104/9C287DE9AAC7/CCAPI/cc_api_call_alert:
    Interface=0x3183EBD8, Progress Indication=NULL(0), Signal 
Indication=NOT PRESENT(255)
Nov 11 13:03:39.871: //104/9C287DE9AAC7/CCAPI/cc_api_call_alert:
    Call Entry(Retry Count=0, Responsed=TRUE)
Nov 11 13:03:39.871: //103/9C287DE9AAC7/CCAPI/ccCallAlert:
    Progress Indication=NULL(0), Signal Indication=NOT PRESENT(255)
Nov 11 13:03:39.871: //103/9C287DE9AAC7/CCAPI/ccCallAlert:
    Call Entry(Responsed=TRUE, Alert Sent=TRUE)
Nov 11 13:03:39.871: 
//104/9C287DE9AAC7/CCAPI/cc_api_get_called_ccm_detected:
    CallInfo(ccm detected=0)
Nov 11 13:03:39.871: //103/9C287DE9AAC7/CCAPI/ccCallNotify:
    Data Bitmask=0x7, Call Id=103
Nov 11 13:03:39.871: 
//104/9C287DE9AAC7/CCAPI/cc_api_get_called_ccm_detected:
    CallInfo(ccm detected=0)
Nov 11 13:03:39.871: //103/9C287DE9AAC7/CCAPI/cc_api_get_delay_xport:
    CallInfo(delay xport=FALSE)
Nov 11 13:03:46.043: ISDN Se0/0/0:15 Q931: RX <- CONNECT pd = 8  callref 
= 0x809D
         Progress Ind i = 0x8182 - Destination address is non-ISDN
         Connected Number i = 0x0180, '49160'
Nov 11 13:03:46.043: %ISDN-6-CONNECT: Interface Serial0/0/0:0 is now 
connected to 160 N/A
Nov 11 13:03:46.043: ISDN Se0/0/0:15 Q931: TX -> CONNECT_ACK pd = 8  
callref = 0x009D
Nov 11 13:03:46.043: //104/9C287DE9AAC7/CCAPI/cc_api_call_connected:
    Interface=0x3183EBD8, Data Bitmask=0x1, Progress 
Indication=DESTINATION IS NON ISDN(2),
    Connection Handle=0
Nov 11 13:03:46.043: //104/9C287DE9AAC7/CCAPI/cc_api_call_connected:
    Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
Nov 11 13:03:46.047: //103/9C287DE9AAC7/CCAPI/ccConferenceCreate:
    (confID=0x2A6C8EB4, callID1=0x67, gcid=0-0-0-0, tag=0x0)
Nov 11 13:03:46.047: //104/9C287DE9AAC7/CCAPI/ccConferenceCreate:
    (confID=0x2A6C8EB4, callID2=0x68, gcid=0-0-0-0, tag=0x0)
Nov 11 13:03:46.047: //103/9C287DE9AAC7/CCAPI/ccConferenceCreate:
    Conference Id=0x2A6C8EB4, Call Id1=103, Call Id2=104, Tag=0x0
Nov 11 13:03:46.047: //103/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

Nov 11 13:03:46.047: cc_api_get_xcode_stream : 4702
Nov 11 13:03:46.047: //103/9C287DE9AAC7/CCAPI/cc_api_bridge_done:
    Conference Id=0x19, Source Interface=0x2AF60854, Source Call Id=103,
    Destination Call Id=104, Disposition=0x0, Tag=0x0
Nov 11 13:03:46.047: //104/9C287DE9AAC7/CCAPI/cc_api_bridge_done:
    Conference Id=0x19, Source Interface=0x3183EBD8, Source Call Id=104,
    Destination Call Id=103, Disposition=0x0, Tag=0xFFFFFFFF
Nov 11 13:03:46.047: //103/9C287DE9AAC7/CCAPI/cc_generic_bridge_done:
    Conference Id=0x19, Source Interface=0x3183EBD8, Source Call Id=104,
    Destination Call Id=103, Disposition=0x0, Tag=0xFFFFFFFF
Nov 11 13:03:46.047: //103/9C287DE9AAC7/CCAPI/ccConferenceCreate:
    Call Entry(Conference Id=0x19, Destination Call Id=104)
Nov 11 13:03:46.047: //104/9C287DE9AAC7/CCAPI/ccConferenceCreate:
    Call Entry(Conference Id=0x19, Destination Call Id=103)
Nov 11 13:03:46.047: //104/9C287DE9AAC7/CCAPI/cc_api_caps_ind:
    Destination Interface=0x2AF60854, Destination Call Id=103, Source 
Call Id=104,
    Caps(Codec=0x1, Fax Rate=0x1, Vad=0x1,
    Modem=0x2, Codec Bytes=20, Signal Type=3)
Nov 11 13:03:46.047: //104/9C287DE9AAC7/CCAPI/cc_api_caps_ind:
    Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
    Playout Max=1000(ms), Fax Nom=300(ms))
Nov 11 13:03:46.047: //103/9C287DE9AAC7/CCAPI/ccCallConnect:
    Progress Indication=DESTINATION IS NON ISDN(2), Data Bitmask=0x1
Nov 11 13:03:46.047: 
//104/9C287DE9AAC7/CCAPI/cc_api_get_called_ccm_detected:
    CallInfo(ccm detected=0)
Nov 11 13:03:46.047: //103/9C287DE9AAC7/CCAPI/ccCallConnect:
    Call Entry(Connected=TRUE, Responsed=TRUE)
Nov 11 13:03:46.047: //103/9C287DE9AAC7/CCAPI/ccCallNotify:
    Data Bitmask=0x7, Call Id=103
Nov 11 13:03:46.047: 
//104/9C287DE9AAC7/CCAPI/cc_api_get_called_ccm_detected:
    CallInfo(ccm detected=0)
Nov 11 13:03:46.047: //103/9C287DE9AAC7/CCAPI/cc_api_caps_ind:
    Destination Interface=0x3183EBD8, Destination Call Id=104, Source 
Call Id=103,
    Caps(Codec=0x4, Fax Rate=0x1, Vad=0x1,
    Modem=0x2, Codec Bytes=20, Signal Type=2)
Nov 11 13:03:46.047: //103/9C287DE9AAC7/CCAPI/cc_api_caps_ind:
    Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
    Playout Max=1000(ms), Fax Nom=300(ms))
Nov 11 13:03:46.047: //103/9C287DE9AAC7/CCAPI/cc_api_caps_ack:
    Destination Interface=0x3183EBD8, Destination Call Id=104, Source 
Call Id=103,
    Caps(Codec=g729r8(0x4), Fax Rate=FAX_RATE_NONE(0x1), Vad=OFF(0x1),
    Modem=ON(0x2), Codec Bytes=20, Signal Type=2, Seq Num Start=6330)
Nov 11 13:03:46.051: //104/9C287DE9AAC7/CCAPI/cc_api_caps_ack:
    Destination Interface=0x2AF60854, Destination Call Id=103, Source 
Call Id=104,
    Caps(Codec=g729r8(0x4), Fax Rate=FAX_RATE_NONE(0x1), Vad=OFF(0x1),
    Modem=ON(0x2), Codec Bytes=20, Signal Type=2, Seq Num Start=6330)
Nov 11 13:03:46.051: //103/9C287DE9AAC7/CCAPI/cc_process_notify_bridge_done:
    Conference Id=0x19, Call Id1=103, Call Id2=104
Nov 11 13:03:46.051: //104/9C287DE9AAC7/CCAPI/cc_api_voice_mode_event:
    Call Id=104
Nov 11 13:03:46.051: //104/9C287DE9AAC7/CCAPI/cc_api_voice_mode_event:
    Call Entry(Context=0x2A6971EC)

  Nov 11 13:03:51.075: //103/9C287DE9AAC7/CCAPI/cc_api_call_disconnected:
    Cause Value=41, Interface=0x2AF60854, Call Id=103
Nov 11 13:03:51.075: //103/9C287DE9AAC7/CCAPI/cc_api_call_disconnected:
    Call Entry(Responsed=TRUE, Cause Value=41, Retry Count=0)
Nov 11 13:03:51.075: //103/9C287DE9AAC7/CCAPI/ccConferenceDestroy:
    Conference Id=0x19, Tag=0x0
Nov 11 13:03:51.075: //103/9C287DE9AAC7/CCAPI/cc_api_bridge_drop_done:
    Conference Id=0x19, Source Interface=0x2AF60854, Source Call Id=103,
    Destination Call Id=104, Disposition=0x0, Tag=0x0
Nov 11 13:03:51.075: //104/9C287DE9AAC7/CCAPI/cc_api_bridge_drop_done:
    Conference Id=0x19, Source Interface=0x3183EBD8, Source Call Id=104,
    Destination Call Id=103, Disposition=0x0, Tag=0x0
Nov 11 13:03:51.075: //103/9C287DE9AAC7/CCAPI/cc_generic_bridge_done:
    Conference Id=0x19, Source Interface=0x3183EBD8, Source Call Id=104,
    Destination Call Id=103, Disposition=0x0, Tag=0x0
Nov 11 13:03:51.075: //103/9C287DE9AAC7/CCAPI/ccCallDisconnect:
    Cause Value=41, Tag=0x0, Call Entry(Previous Disconnect Cause=0, 
Disconnect Cause=41)
Nov 11 13:03:51.075: //103/9C287DE9AAC7/CCAPI/ccCallDisconnect:
    Cause Value=41, Call Entry(Responsed=TRUE, Cause Value=41)
Nov 11 13:03:51.075: //103/9C287DE9AAC7/CCAPI/cc_api_get_transfer_info:
    Transfer Number Is Null
Nov 11 13:03:51.075: //104/9C287DE9AAC7/CCAPI/ccCallDisconnect:
    Cause Value=41, Tag=0x0, Call Entry(Previous Disconnect Cause=0, 
Disconnect Cause=0)
Nov 11 13:03:51.075: //104/9C287DE9AAC7/CCAPI/ccCallDisconnect:
    Cause Value=41, Call Entry(Responsed=TRUE, Cause Value=41)
Nov 11 13:03:51.075: //104/9C287DE9AAC7/CCAPI/cc_api_get_transfer_info:
    Transfer Number Is Null
Nov 11 13:03:51.087: //103/9C287DE9AAC7/CCAPI/cc_api_get_transfer_info:
    Transfer Number Is Null
Nov 11 13:03:51.087: //103/9C287DE9AAC7/CCAPI/cc_api_call_disconnect_done:
    Disposition=0, Interface=0x2AF60854, Tag=0x0, Call Id=103,
    Call Entry(Disconnect Cause=41, Voice Class Cause Code=0, Retry Count=0)
Nov 11 13:03:51.087: //103/9C287DE9AAC7/CCAPI/cc_api_call_disconnect_done:
    Call Disconnect Event Sent
Nov 11 13:03:51.087: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Nov 11 13:03:51.087: :cc_free_feature_vsa freeing 31D711C8
Nov 11 13:03:51.087: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Nov 11 13:03:51.087:  vsacount in free is 1
Nov 11 13:03:51.099: %ISDN-6-DISCONNECT: Interface Serial0/0/0:0  
disconnected from 160 , call lasted 5 seconds
Nov 11 13:03:51.099: ISDN Se0/0/0:15 Q931: TX -> DISCONNECT pd = 8  
callref = 0x009D
         Cause i = 0x82A9 - Temporary failure

BR
Anthony
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20111111/5d7a3fd1/attachment.html>

More information about the cisco-voip mailing list