Delay in DID calls

[mohammedobaid]

Dear all,

We have  3 CUCM Servers and  a VG, 4 E1 lines, 1000 DID numbers, whenever we are receiving a call on this numbers it's getting delayed or getting drop, It's taking around 20-24 seconds to connect 

Below are the dial-peer configurations for incoming calls

dial-peer voice 2 pots
incoming called-number 8...
direct-inward-dial
port 2/0:5

dial-peer voice 3 pots
description PSTN-TO-IPphone(861-deleted-from-PSTN)
preference 1
incoming called-number 8...
direct-inward-dial
port 1/1:3

Can any one guide what kind of changes need to be made

[Suresh Hudda]

It's just because of dialplan overlapping, can u attach 'debug voip ccapi inout' of one test call, along with sh run | s dial-peer

Suresh

[mohammedobaid]

dial-peer voice 999000 pots
service mgcpapp
port 0/0/0
dial-peer voice 999001 pots
service mgcpapp
port 0/0/1
dial-peer voice 999002 pots
service mgcpapp
port 0/0/2
dial-peer voice 999003 pots
service mgcpapp
port 0/0/3
dial-peer voice 999010 pots
service mgcpapp
port 0/1/0
dial-peer voice 8023 voip
description incoming to Rfax Server(DTMF-Unified)
destination-pattern 8023
session protocol sipv2
session target ipv4:10.200.10.143
session transport udp
codec g711alaw
fax protocol t38 ls-redundancy 2 hs-redundancy 0 fallback none
no vad
dial-peer voice 8043 voip
description incoming to Rfax Server(DID for each user)
destination-pattern 8043
session protocol sipv2
session target ipv4:10.200.10.147
session transport udp
codec g711alaw
fax protocol t38 ls-redundancy 2 hs-redundancy 0 fallback none
no vad
dial-peer voice 8229 voip
description incoming to Rfax Server(DID for each user)
destination-pattern 8229
session protocol sipv2
session target ipv4:10.200.10.147
session transport udp
codec g711alaw
fax protocol t38 ls-redundancy 2 hs-redundancy 0 fallback none
no vad
dial-peer voice 999013 pots
service mgcpapp
port 0/1/3
dial-peer voice 8530 voip
description incoming to Rfax Server(DID for each user)
destination-pattern 8530
session protocol sipv2
session target ipv4:10.200.10.147
session transport udp
codec g711alaw
fax protocol t38 ls-redundancy 2 hs-redundancy 0 fallback none
no vad
dial-peer voice 8533 voip
description incoming to Rfax Server(DID for each user)
destination-pattern 8533
session protocol sipv2
session target ipv4:10.200.10.147
session transport udp
codec g711alaw
fax protocol t38 ls-redundancy 2 hs-redundancy 0 fallback none
no vad
dial-peer voice 4 pots
translation-profile outgoing CallerID
destination-pattern .T
port 1/0:2
forward-digits all
dial-peer voice 5 pots
translation-profile outgoing CallerID
destination-pattern .T
port 1/1:4
forward-digits all
dial-peer voice 8500 voip
description incoming to Rfax Server(DID for each user)
destination-pattern 8500
session protocol sipv2
session target ipv4:10.200.10.147
session transport udp
codec g711alaw
fax protocol t38 ls-redundancy 2 hs-redundancy 0 fallback none
no vad
dial-peer voice 8338 voip
description incoming to Rfax Server(DID for each user)
destination-pattern 8338
session protocol sipv2
session target ipv4:10.200.10.147
session transport udp
codec g711alaw
fax protocol t38 ls-redundancy 2 hs-redundancy 0 fallback none
no vad
dial-peer voice 999011 pots
service mgcpapp
port 0/1/1
dial-peer voice 2 pots
description PSTN-TO-IPphone(861-deleted-from-PSTN)
incoming called-number 8...
direct-inward-dial
port 2/0:5
dial-peer voice 3 pots
description PSTN-TO-IPphone(861-deleted-from-PSTN)
preference 1
incoming called-number 8...
direct-inward-dial
port 1/1:3
dial-peer voice 999012 pots
service mgcpapp
port 0/1/2
dial-peer voice 9 voip
destination-pattern 8...
session target ipv4:10.100.150.10
dtmf-relay h245-alphanumeric
codec g711ulaw
no vad
dial-peer voice 1 pots
description PSTN-TO-IPphone(861-deleted-from-PSTN)
incoming called-number 8...
direct-inward-dial
port 1/0:1
dial-peer voice 8501 voip
description incoming to Rfax Server(DID for each user)
destination-pattern 8501
session protocol sipv2
session target ipv4:10.200.10.147
session transport udp
codec g711alaw
fax protocol t38 ls-redundancy 2 hs-redundancy 0 fallback none
no vad
dial-peer voice 8502 voip
description incoming to Rfax Server(DID for each user)
destination-pattern 8502
session protocol sipv2
session target ipv4:10.200.10.147
session transport udp
codec g711alaw
fax protocol t38 ls-redundancy 2 hs-redundancy 0 fallback none
no vad
dial-peer voice 8505 voip
description incoming to Rfax Server(DID for each user)
destination-pattern 8505
session protocol sipv2
session target ipv4:10.200.10.147
session transport udp
codec g711alaw
fax protocol t38 ls-redundancy 2 hs-redundancy 0 fallback none
no vad
dial-peer voice 8511 voip
description incoming to Rfax Server(DID for each user)
destination-pattern 8511
session protocol sipv2
session target ipv4:10.200.10.147
session transport udp
codec g711alaw
fax protocol t38 ls-redundancy 2 hs-redundancy 0 fallback none
no vad
dial-peer voice 8376 voip
description incoming to Rfax Server(DID for each user)
destination-pattern 8376
session protocol sipv2
session target ipv4:10.200.10.147
session transport udp
codec g711alaw
fax protocol t38 ls-redundancy 2 hs-redundancy 0 fallback none
no vad
dial-peer voice 8802 voip
description incoming to Rfax Server(DID for each user)
destination-pattern 8802
session protocol sipv2
session target ipv4:10.200.10.147
session transport udp
codec g711alaw
fax protocol t38 ls-redundancy 2 hs-redundancy 0 fallback none
no vad

[Suresh Hudda]

As per log, it's outbound call and don't see issue at gateway level. Did you observe that call is hitting to gateway late while you enable debug  ?

Do you have overlapping dial plan in cucm ?.just check route plan report in cucm (starting digit 8), if possible pls attach snap shot of that.

Suresh

[mohammedobaid]

Actually, I dialed from the same system
outgoing was from 8616658 to 8618800
incoming number is 8618800
Our DID range is 8000-8999

[Suresh Hudda]

Delay in connecting of incoming calls or outgoing calls ?

Suresh

[mohammedobaid]

We have an issue in incoming calls
either you dialed from mobile, landline or any other source to any of our incoming numbers theirs a lot of delay before connecting 

sometimes even there's a drop in calls

[Suresh Hudda]

But you have attached logs of outgoing call :-( can u pls attach logs of incoming call ?

Suresh

[mohammedobaid]

this is the incoming call details
outgoing number 8618888
incoming number 8800

*Jun 20 10:55:10.184: :cc_get_feature_vsa malloc success
*Jun 20 10:55:10.184: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Jun 20 10:55:10.184: cc_get_feature_vsa count is 14
*Jun 20 10:55:10.184: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Jun 20 10:55:10.184: :FEATURE_VSA attributes are: feature_name:0,feature_time:1730050648,feature_id:1888269
*Jun 20 10:55:10.184: //1891481/4AAE0B3AA83C/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=1, FlowMode=1
*Jun 20 10:55:10.184: //1891481/4AAE0B3AA83C/CCAPI/ccCallSetContext:
Context=0x67E6508C
*Jun 20 10:55:10.184: //1891480/4AAE0B3AA83C/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=9
*Jun 20 10:55:10.192: //1891481/4AAE0B3AA83C/CCAPI/cc_api_set_called_ccm_detected:
CallInfo(called ccm detected=TRUE ccmVersion 3)
*Jun 20 10:55:10.192: //1891481/4AAE0B3AA83C/CCAPI/cc_api_call_proceeding:
Interface=0x66E40C1C, Progress Indication=NULL(0)
*Jun 20 10:55:10.208: //1891481/4AAE0B3AA83C/CCAPI/cc_api_set_called_ccm_detected:
CallInfo(called ccm detected=TRUE ccmVersion 3)
*Jun 20 10:55:10.208: //1891481/4AAE0B3AA83C/CCAPI/cc_api_set_delay_xport:
CallInfo(delay xport=TRUE)
*Jun 20 10:55:10.208: //1891481/4AAE0B3AA83C/CCAPI/cc_api_call_alert:
Interface=0x66E40C1C, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
*Jun 20 10:55:10.208: //1891481/4AAE0B3AA83C/CCAPI/cc_api_call_alert:
Call Entry(Retry Count=0, Responsed=TRUE)
*Jun 20 10:55:10.212: //1891480/4AAE0B3AA83C/CCAPI/ccCallAlert:
Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
*Jun 20 10:55:10.212: //1891480/4AAE0B3AA83C/CCAPI/ccCallAlert:
Call Entry(Responsed=TRUE, AlertSent=TRUE)
*Jun 20 10:55:10.392: //1891481/4AAE0B3AA83C/CCAPI/cc_api_set_called_ccm_detected:
CallInfo(called ccm detected=TRUE ccmVersion 3)
*Jun 20 10:55:10.392: //1891481/4AAE0B3AA83C/CCAPI/cc_api_call_notify:
Data Bitmask=0x5, Interface=0x66E40C1C, Call Id=1891481
*Jun 20 10:55:10.392: //1891481/4AAE0B3AA83C/CCAPI/cc_api_get_ssCTreRoutingNotSupported:
CallInfo(ssCTreRoutingNotSupported=FALSE)
*Jun 20 10:55:10.392: //1891481/4AAE0B3AA83C/CCAPI/cc_api_get_ccm_detected:
CallInfo(ccm detected=TRUE)
*Jun 20 10:55:10.392: //1891480/4AAE0B3AA83C/CCAPI/ccCallNotify:
Data Bitmask=0x5, Call Id=1891480
*Jun 20 10:55:10.400: //1891481/4AAE0B3AA83C/CCAPI/cc_api_call_connected:
Interface=0x66E40C1C, Data Bitmask=0x0, Progress Indication=NULL(0),
Connection Handle=0
*Jun 20 10:55:10.400: //1891481/4AAE0B3AA83C/CCAPI/cc_api_call_connected:
Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
*Jun 20 10:55:10.400: //1891481/4AAE0B3AA83C/CCAPI/cc_api_set_called_ccm_detected:
CallInfo(called ccm detected=TRUE ccmVersion 3)
*Jun 20 10:55:10.400: //1891481/4AAE0B3AA83C/CCAPI/cc_api_call_notify:
Data Bitmask=0x5, Interface=0x66E40C1C, Call Id=1891481
*Jun 20 10:55:10.404: //1891480/4AAE0B3AA83C/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Null,
Tone Direction=Network, Params=0x0, Call Id=1891480
*Jun 20 10:55:10.404: //1891480/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:
(confID=0x679D61E4, callID1=0x1CDC98, callID2=0x1CDC99, tag=0x0)
*Jun 20 10:55:10.404: //1891480/4AAE0B3AA83C/CCAPI/ccConferenceCreate:
Conference Id=0x679D61E4, Call Id1=1891480, Call Id2=1891481, Tag=0x0
*Jun 20 10:55:10.404: //1891480/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0xC585E, Source Interface=0x675241E4, Source Call Id=1891480,
Destination Call Id=1891481, Disposition=0x0, Tag=0xFFFFFFFF
*Jun 20 10:55:10.404: //1891481/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Jun 20 10:55:10.404: cc_api_get_xcode_stream : 4381
*Jun 20 10:55:10.404: //1891481/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0xC585E, Source Interface=0x66E40C1C, Source Call Id=1891481,
Destination Call Id=1891480, Disposition=0x0, Tag=0x0
*Jun 20 10:55:10.404: //1891480/4AAE0B3AA83C/CCAPI/cc_generic_bridge_done:
Conference Id=0xC585E, Source Interface=0x66E40C1C, Source Call Id=1891481,
Destination Call Id=1891480, Disposition=0x0, Tag=0x0
*Jun 20 10:55:10.404: //1891480/4AAE0B3AA83C/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0xC585E, Destination Call Id=1891481)
*Jun 20 10:55:10.404: //1891481/4AAE0B3AA83C/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0xC585E, Destination Call Id=1891480)
*Jun 20 10:55:10.404: //1891480/4AAE0B3AA83C/CCAPI/cc_api_caps_ind:
Destination Interface=0x66E40C1C, Destination Call Id=1891481, Source Call Id=1891480,
Caps(Codec=0x1, Fax Rate=0x1, Vad=0x1,
Modem=0x2, Codec Bytes=20, Signal Type=3)
*Jun 20 10:55:10.404: //1891480/4AAE0B3AA83C/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=250(ms), Fax Nom=300(ms))
*Jun 20 10:55:10.404: //1891480/4AAE0B3AA83C/CCAPI/cc_process_notify_bridge_done:
Conference Id=0xC585E, Call Id1=1891480, Call Id2=1891481
*Jun 20 10:55:10.404: //1891481/4AAE0B3AA83C/CCAPI/cc_api_caps_ind:
Destination Interface=0x675241E4, Destination Call Id=1891480, Source Call Id=1891481,
Caps(Codec=0x1, Fax Rate=0x2, Vad=0x1,
Modem=0x0, Codec Bytes=160, Signal Type=2)
*Jun 20 10:55:10.404: //1891481/4AAE0B3AA83C/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=250(ms), Fax Nom=300(ms))
*Jun 20 10:55:10.404: //1891481/4AAE0B3AA83C/CCAPI/cc_api_caps_ack:
Destination Interface=0x675241E4, Destination Call Id=1891480, Source Call Id=1891481,
Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1),
Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=3414)
*Jun 20 10:55:10.404: //1891481/4AAE0B3AA83C/CCAPI/cc_api_get_ssCTreRoutingNotSupported:
CallInfo(ssCTreRoutingNotSupported=FALSE)
*Jun 20 10:55:10.404: //1891481/4AAE0B3AA83C/CCAPI/cc_api_get_ccm_detected:
CallInfo(ccm detected=TRUE)
*Jun 20 10:55:10.404: //1891480/4AAE0B3AA83C/CCAPI/ccCallNotify:
Data Bitmask=0x5, Call Id=1891480
*Jun 20 10:55:10.404: //1891480/4AAE0B3AA83C/CCAPI/ccCallConnect:
Progress Indication=NULL(0), Data Bitmask=0x0
*Jun 20 10:55:10.404: //1891480/4AAE0B3AA83C/CCAPI/ccCallConnect:
Call Entry(Connected=TRUE, Responsed=TRUE)
*Jun 20 10:55:11.380: //1891480/4AAE0B3AA83C/CCAPI/cc_api_caps_ack:
Destination Interface=0x66E40C1C, Destination Call Id=1891481, Source Call Id=1891480,
Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1),
Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=3414)
*Jun 20 10:55:11.380: //1891480/4AAE0B3AA83C/CCAPI/cc_api_voice_mode_event:
Call Id=1891480
*Jun 20 10:55:11.380: //1891480/4AAE0B3AA83C/CCAPI/cc_api_voice_mode_event:
Call Entry(Context=0x67C6D6B8)
*Jun 20 10:55:12.544: //-1/4C16C22EA841/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=
----- ccCallInfo IE subfields -----
cisco-ani=148618888
cisco-anitype=3
cisco-aniplan=13
cisco-anipi=0
cisco-anisi=0
dest=8800
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=0 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

*Jun 20 10:55:12.544: //-1/4C16C22EA841/CCAPI/cc_api_call_setup_ind_common:
Interface=0x675241E4, Call Info(
Calling Number=148618888,(Calling Name=)(TON=Network, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=8800(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
Incoming Dial-peer=2, 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=-1
Sub Calling(TON=Abbreviated, NPI=Data, Data=K8fd=Xg
P`mw@gPeJKgPeJK`o`mw@eQ, Length=103)
Sub Called(TON=Abbreviated, NPI=Unknown, Data=PeJK`o`mw@eQ, Length=156)
*Jun 20 10:55:12.544: //-1/4C16C22EA841/CCAPI/ccCheckClipClir:
In: Calling Number=148618888(TON=Network, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Jun 20 10:55:12.544: //-1/4C16C22EA841/CCAPI/ccCheckClipClir:
Out: Calling Number=148618888(TON=Network, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Jun 20 10:55:12.544: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Jun 20 10:55:12.544: :cc_get_feature_vsa malloc success
*Jun 20 10:55:12.544: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Jun 20 10:55:12.544: cc_get_feature_vsa count is 15
*Jun 20 10:55:12.544: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Jun 20 10:55:12.544: :FEATURE_VSA attributes are: feature_name:0,feature_time:1730038552,feature_id:1888270
*Jun 20 10:55:12.544: //1891482/4C16C22EA841/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=148618888(TON=Network, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=8800(TON=Unknown, NPI=Unknown))
*Jun 20 10:55:12.544: //1891482/4C16C22EA841/CCAPI/cc_process_call_setup_ind:
Event=0x669B4760
*Jun 20 10:55:12.544: //1891482/4C16C22EA841/CCAPI/ccCallSetContext:
Context=0x67F8A3D4
*Jun 20 10:55:12.544: //1891482/4C16C22EA841/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 1891482 with tag 2 to app "_ManagedAppProcess_Default"
*Jun 20 10:55:12.544: //1891482/4C16C22EA841/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
*Jun 20 10:55:12.548: //1891482/4C16C22EA841/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=9, Params=0x67E6D314, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
*Jun 20 10:55:12.548: //1891482/4C16C22EA841/CCAPI/ccCheckClipClir:
In: Calling Number=148618888(TON=Network, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Jun 20 10:55:12.548: //1891482/4C16C22EA841/CCAPI/ccCheckClipClir:
Out: Calling Number=148618888(TON=Network, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Jun 20 10:55:12.548: //1891482/4C16C22EA841/CCAPI/ccCallSetupRequest:
Destination Pattern=8..., Called Number=8800, Digit Strip=FALSE
*Jun 20 10:55:12.548: //1891482/4C16C22EA841/CCAPI/ccCallSetupRequest:
Calling Number=148618888(TON=Network, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=8800(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=
Account Number=, Final Destination Flag=TRUE,
Guid=4C16C22E-360C-11E6-A841-912F3A5D796D, Outgoing Dial-peer=9
*Jun 20 10:55:12.548: //1891482/4C16C22EA841/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=
----- ccCallInfo IE subfields -----
cisco-ani=148618888
cisco-anitype=3
cisco-aniplan=13
cisco-anipi=0
cisco-anisi=0
dest=8800
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=0 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

*Jun 20 10:55:12.548: //1891482/4C16C22EA841/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x66E40C1C, Interface Type=1, Destination=, Mode=0x0,
Call Params(Calling Number=148618888,(Calling Name=)(TON=Network, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=8800(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=9, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
Sub Calling(TON=Abbreviated, NPI=Data, Data=K8fd=Xg
P`mw@gPeJKgPeJK`o`mw@eQ, Length=103)
Sub Called(TON=Abbreviated, NPI=Unknown, Data=PeJK`o`mw@eQ, Length=156)
*Jun 20 10:55:12.548: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Jun 20 10:55:12.548: :cc_get_feature_vsa malloc success
*Jun 20 10:55:12.548: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Jun 20 10:55:12.548: cc_get_feature_vsa count is 16
*Jun 20 10:55:12.548: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Jun 20 10:55:12.548: :FEATURE_VSA attributes are: feature_name:0,feature_time:1730042656,feature_id:1888271
*Jun 20 10:55:12.548: //1891483/4C16C22EA841/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=1, FlowMode=1
*Jun 20 10:55:12.548: //1891483/4C16C22EA841/CCAPI/ccCallSetContext:
Context=0x67E6D2C4
*Jun 20 10:55:12.548: //1891482/4C16C22EA841/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=9
*Jun 20 10:55:12.692: //1891483/4C16C22EA841/CCAPI/cc_api_set_called_ccm_detected:
CallInfo(called ccm detected=TRUE ccmVersion 3)
*Jun 20 10:55:12.692: //1891483/4C16C22EA841/CCAPI/cc_api_call_proceeding:
Interface=0x66E40C1C, Progress Indication=NULL(0)
*Jun 20 10:55:12.712: //1891483/4C16C22EA841/CCAPI/cc_api_set_called_ccm_detected:
CallInfo(called ccm detected=TRUE ccmVersion 3)
*Jun 20 10:55:12.712: //1891483/4C16C22EA841/CCAPI/cc_api_set_delay_xport:
CallInfo(delay xport=TRUE)
*Jun 20 10:55:12.712: //1891483/4C16C22EA841/CCAPI/cc_api_call_alert:
Interface=0x66E40C1C, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
*Jun 20 10:55:12.712: //1891483/4C16C22EA841/CCAPI/cc_api_call_alert:
Call Entry(Retry Count=0, Responsed=TRUE)
*Jun 20 10:55:12.712: //1891482/4C16C22EA841/CCAPI/ccCallAlert:
Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
*Jun 20 10:55:12.712: //1891482/4C16C22EA841/CCAPI/ccCallAlert:
Call Entry(Responsed=TRUE, AlertSent=TRUE)
*Jun 20 10:55:13.448: //1891483/4C16C22EA841/CCAPI/cc_api_set_called_ccm_detected:
CallInfo(called ccm detected=TRUE ccmVersion 3)
*Jun 20 10:55:13.448: //1891483/4C16C22EA841/CCAPI/cc_api_call_notify:
Data Bitmask=0x5, Interface=0x66E40C1C, Call Id=1891483
*Jun 20 10:55:13.452: //1891483/4C16C22EA841/CCAPI/cc_api_get_ssCTreRoutingNotSupported:
CallInfo(ssCTreRoutingNotSupported=FALSE)
*Jun 20 10:55:13.452: //1891483/4C16C22EA841/CCAPI/cc_api_get_ccm_detected:
CallInfo(ccm detected=TRUE)
*Jun 20 10:55:13.452: //1891482/4C16C22EA841/CCAPI/ccCallNotify:
Data Bitmask=0x5, Call Id=1891482
*Jun 20 10:55:13.964: //1891483/4C16C22EA841/CCAPI/cc_api_call_connected:
Interface=0x66E40C1C, Data Bitmask=0x0, Progress Indication=NULL(0),
Connection Handle=0
*Jun 20 10:55:13.964: //1891483/4C16C22EA841/CCAPI/cc_api_call_connected:
Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
*Jun 20 10:55:13.964: //1891483/4C16C22EA841/CCAPI/cc_api_set_called_ccm_detected:
CallInfo(called ccm detected=TRUE ccmVersion 3)
*Jun 20 10:55:13.964: //1891483/4C16C22EA841/CCAPI/cc_api_call_notify:
Data Bitmask=0x5, Interface=0x66E40C1C, Call Id=1891483
*Jun 20 10:55:13.964: //1891482/4C16C22EA841/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Null,
Tone Direction=Network, Params=0x0, Call Id=1891482
*Jun 20 10:55:13.964: //1891482/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:
(confID=0x67DB678C, callID1=0x1CDC9A, callID2=0x1CDC9B, tag=0x0)
*Jun 20 10:55:13.964: //1891482/4C16C22EA841/CCAPI/ccConferenceCreate:
Conference Id=0x67DB678C, Call Id1=1891482, Call Id2=1891483, Tag=0x0
*Jun 20 10:55:13.964: //1891482/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0xC585F, Source Interface=0x675241E4, Source Call Id=1891482,
Destination Call Id=1891483, Disposition=0x0, Tag=0xFFFFFFFF
*Jun 20 10:55:13.964: //1891483/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Jun 20 10:55:13.964: cc_api_get_xcode_stream : 4381
*Jun 20 10:55:13.964: //1891483/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0xC585F, Source Interface=0x66E40C1C, Source Call Id=1891483,
Destination Call Id=1891482, Disposition=0x0, Tag=0x0
*Jun 20 10:55:13.964: //1891482/4C16C22EA841/CCAPI/cc_generic_bridge_done:
Conference Id=0xC585F, Source Interface=0x66E40C1C, Source Call Id=1891483,
Destination Call Id=1891482, Disposition=0x0, Tag=0x0
*Jun 20 10:55:13.964: //1891482/4C16C22EA841/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0xC585F, Destination Call Id=1891483)
*Jun 20 10:55:13.964: //1891483/4C16C22EA841/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0xC585F, Destination Call Id=1891482)
*Jun 20 10:55:13.964: //1891482/4C16C22EA841/CCAPI/cc_api_caps_ind:
Destination Interface=0x66E40C1C, Destination Call Id=1891483, Source Call Id=1891482,
Caps(Codec=0x1, Fax Rate=0x1, Vad=0x1,
Modem=0x2, Codec Bytes=20, Signal Type=3)
*Jun 20 10:55:13.964: //1891482/4C16C22EA841/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=250(ms), Fax Nom=300(ms))
*Jun 20 10:55:13.968: //1891482/4C16C22EA841/CCAPI/cc_process_notify_bridge_done:
Conference Id=0xC585F, Call Id1=1891482, Call Id2=1891483
*Jun 20 10:55:13.968: //1891483/4C16C22EA841/CCAPI/cc_api_caps_ind:
Destination Interface=0x675241E4, Destination Call Id=1891482, Source Call Id=1891483,
Caps(Codec=0x1, Fax Rate=0x2, Vad=0x1,
Modem=0x0, Codec Bytes=160, Signal Type=2)
*Jun 20 10:55:13.968: //1891483/4C16C22EA841/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=250(ms), Fax Nom=300(ms))
*Jun 20 10:55:13.968: //1891483/4C16C22EA841/CCAPI/cc_api_caps_ack:
Destination Interface=0x675241E4, Destination Call Id=1891482, Source Call Id=1891483,
Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1),
Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=691)
*Jun 20 10:55:13.968: //1891483/4C16C22EA841/CCAPI/cc_api_get_ssCTreRoutingNotSupported:
CallInfo(ssCTreRoutingNotSupported=FALSE)
*Jun 20 10:55:13.968: //1891483/4C16C22EA841/CCAPI/cc_api_get_ccm_detected:
CallInfo(ccm detected=TRUE)
*Jun 20 10:55:13.968: //1891482/4C16C22EA841/CCAPI/ccCallNotify:
Data Bitmask=0x5, Call Id=1891482
*Jun 20 10:55:13.968: //1891482/4C16C22EA841/CCAPI/ccCallConnect:
Progress Indication=NULL(0), Data Bitmask=0x0
*Jun 20 10:55:13.968: //1891482/4C16C22EA841/CCAPI/ccCallConnect:
Call Entry(Connected=TRUE, Responsed=TRUE)
*Jun 20 10:55:14.064: //1891480/xxxxxxxxxxxx/CCAPI/cc_api_call_digit_begin:
Consume mask is not set. Relaying Digit 6 to dstCallId 0x1CDC99
*Jun 20 10:55:14.840: //1891480/xxxxxxxxxxxx/CCAPI/cc_api_call_digit_end:
Consume mask is not set. Relaying Digit 6 to dstCallId 0x1CDC99
*Jun 20 10:55:14.840: //1891480/xxxxxxxxxxxx/CCAPI/cc_api_call_digit_begin:
Consume mask is not set. Relaying Digit 2 to dstCallId 0x1CDC99
*Jun 20 10:55:14.840: //1891480/xxxxxxxxxxxx/CCAPI/cc_api_call_digit_end:
Consume mask is not set. Relaying Digit 2 to dstCallId 0x1CDC99
*Jun 20 10:55:14.852: //1891482/4C16C22EA841/CCAPI/cc_api_caps_ack:
Destination Interface=0x66E40C1C, Destination Call Id=1891483, Source Call Id=1891482,
Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1),
Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=691)
*Jun 20 10:55:14.860: //1891482/4C16C22EA841/CCAPI/cc_api_voice_mode_event:
Call Id=1891482
*Jun 20 10:55:14.860: //1891482/4C16C22EA841/CCAPI/cc_api_voice_mode_event:
Call Entry(Context=0x67F8A3D4)
*Jun 20 10:55:15.512: //1891480/xxxxxxxxxxxx/CCAPI/cc_api_call_digit_begin:
Consume mask is not set. Relaying Digit 2 to dstCallId 0x1CDC99
*Jun 20 10:55:15.512: //1891480/xxxxxxxxxxxx/CCAPI/cc_api_call_digit_end:
Consume mask is not set. Relaying Digit 2 to dstCallId 0x1CDC99
*Jun 20 10:55:15.516: //1891479/00A0CC7E700A/CCAPI/cc_api_call_alert:
Interface=0x67505858, Progress Indication=INBAND(8), Signal Indication=SIGNAL RINGBACK(1)
*Jun 20 10:55:15.516: //1891479/00A0CC7E700A/CCAPI/cc_api_call_alert:
Call Entry(Retry Count=0, Responsed=TRUE)
*Jun 20 10:55:15.516: //1891479/00A0CC7E700A/CCAPI/cc_api_call_connected:
Interface=0x67505858, Data Bitmask=0x1, Progress Indication=DESTINATION IS NON ISDN(2),
Connection Handle=0
*Jun 20 10:55:15.516: //1891479/00A0CC7E700A/CCAPI/cc_api_call_connected:
Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
*Jun 20 10:55:15.524: //1891478/00A0CC7E700A/CCAPI/ccCallAlert:
Progress Indication=INBAND(8), Signal Indication=SIGNAL RINGBACK(1)
*Jun 20 10:55:15.524: //1891478/00A0CC7E700A/CCAPI/ccCallAlert:
Call Entry(Responsed=TRUE, AlertSent=TRUE)
*Jun 20 10:55:15.524: //1891479/00A0CC7E700A/CCAPI/cc_api_get_called_ccm_detected:
CallInfo(ccm detected=0)
*Jun 20 10:55:15.524: //1891478/00A0CC7E700A/CCAPI/ccCallNotify:
Data Bitmask=0x7, Call Id=1891478
*Jun 20 10:55:15.524: //1891479/00A0CC7E700A/CCAPI/cc_api_get_called_ccm_detected:
CallInfo(ccm detected=0)
*Jun 20 10:55:15.524: //1891478/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:
(confID=0x679D60C4, callID1=0x1CDC96, callID2=0x1CDC97, tag=0x0)
*Jun 20 10:55:15.524: //1891478/00A0CC7E700A/CCAPI/ccConferenceCreate:
Conference Id=0x679D60C4, Call Id1=1891478, Call Id2=1891479, Tag=0x0
*Jun 20 10:55:15.524: //1891478/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Jun 20 10:55:15.524: cc_api_get_xcode_stream : 4381
*Jun 20 10:55:15.524: //1891478/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0xC5860, Source Interface=0x66E40C1C, Source Call Id=1891478,
Destination Call Id=1891479, Disposition=0x0, Tag=0x0
*Jun 20 10:55:15.524: //1891479/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0xC5860, Source Interface=0x67505858, Source Call Id=1891479,
Destination Call Id=1891478, Disposition=0x0, Tag=0xFFFFFFFF
*Jun 20 10:55:15.524: //1891478/00A0CC7E700A/CCAPI/cc_generic_bridge_done:
Conference Id=0xC5860, Source Interface=0x67505858, Source Call Id=1891479,
Destination Call Id=1891478, Disposition=0x0, Tag=0xFFFFFFFF
*Jun 20 10:55:15.524: //1891478/00A0CC7E700A/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0xC5860, Destination Call Id=1891479)
*Jun 20 10:55:15.524: //1891479/00A0CC7E700A/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0xC5860, Destination Call Id=1891478)
*Jun 20 10:55:15.524: //1891479/00A0CC7E700A/CCAPI/cc_api_caps_ind:
Destination Interface=0x66E40C1C, Destination Call Id=1891478, Source Call Id=1891479,
Caps(Codec=0x1, Fax Rate=0x1, Vad=0x1,
Modem=0x2, Codec Bytes=20, Signal Type=3)
*Jun 20 10:55:15.524: //1891479/00A0CC7E700A/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=250(ms), Fax Nom=300(ms))
*Jun 20 10:55:15.524: //1891478/00A0CC7E700A/CCAPI/cc_api_get_delay_xport:
CallInfo(delay xport=FALSE)
*Jun 20 10:55:15.528: //1891478/00A0CC7E700A/CCAPI/cc_process_notify_bridge_done:
Conference Id=0xC5860, Call Id1=1891478, Call Id2=1891479
*Jun 20 10:55:15.528: //1891480/xxxxxxxxxxxx/CCAPI/cc_api_call_digit_begin:
Consume mask is not set. Relaying Digit 2 to dstCallId 0x1CDC99
*Jun 20 10:55:15.528: //1891478/00A0CC7E700A/CCAPI/ccCallConnect:
Progress Indication=DESTINATION IS NON ISDN(2), Data Bitmask=0x1
*Jun 20 10:55:15.528: //1891479/00A0CC7E700A/CCAPI/cc_api_get_called_ccm_detected:
CallInfo(ccm detected=0)
*Jun 20 10:55:15.528: //1891478/00A0CC7E700A/CCAPI/ccCallConnect:
Call Entry(Connected=TRUE, Responsed=TRUE)
*Jun 20 10:55:15.528: //1891478/00A0CC7E700A/CCAPI/ccCallNotify:
Data Bitmask=0x7, Call Id=1891478
*Jun 20 10:55:15.528: //1891479/00A0CC7E700A/CCAPI/cc_api_get_called_ccm_detected:
CallInfo(ccm detected=0)
*Jun 20 10:55:16.156: //1891478/00A0CC7E700A/CCAPI/cc_api_caps_ind:
Destination Interface=0x67505858, Destination Call Id=1891479, Source Call Id=1891478,
Caps(Codec=0x1, Fax Rate=0x2, Vad=0x1,
Modem=0x0, Codec Bytes=160, Signal Type=2)
*Jun 20 10:55:16.156: //1891478/00A0CC7E700A/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=250(ms), Fax Nom=300(ms))
*Jun 20 10:55:16.156: //1891478/00A0CC7E700A/CCAPI/cc_api_caps_ack:
Destination Interface=0x67505858, Destination Call Id=1891479, Source Call Id=1891478,
Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1),
Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=1405)

[Suresh Hudda]

Dear, as Earlier asked..Do you have overlapping dial plan in cucm ?.just check route plan report in cucm (starting digit 8), if possible pls attach snap shot of that.

Suresh

[mohammedobaid]

file is 

[Francisco Granados]

In order to figure out where the delay is, we need to trace the call step by step.

I would recommend that you test by calling your internal phone from your cell phone, that way you can see how long it takes for the call to hit the phone.

1. Debug isdn q931 on the gateway.

2. Debug sccp events

2. Call from your mobile to your desk phone.

3. The moment you see the call hit the gateway - Was there any delay?

4. How long does it take to ring the phone?

5. Once the call is connected, do "sh sccp connections".

Post the debug results as well as call manager logs for that timeframe. Right after the call, you can go to RTMT -> Trace and log central -> Collect logs -> Call manager -> Relative range last 5 minutes.

Thanks,

FG

[mohammedobaid]

1. Debug isdn q931 on the gateway.
 VG02#debug isdn q931
^
% Invalid input detected at '^' marker.

Gateway is not accepting this command

2. Debug sccp events

debug sccp events
Skinny Client Control Protocol events debugging is on
VG02#term mon
VG02#sh sccp connection

Total number of active session(s) 0, and connection(s) 0

3. The moment you see the call hit the gateway - Was there any delay?

Yes, there is a delay 

4. How long does it take to ring the phone?
20 -21 seconds delay or sometimes its not getting connected