Unable to transfer calls

[Mario Manzano]

Hello Everyone!

We are having a problem when someone calls into the main number and the receptionist tries to transfer the call to an extension (this only happens on 3 extensions on a VG224) it gives her a fast busy.

However, if she dials the extension directly she can reach it with no problems.

Anyone had this problem or seen it before?

Many thanks!

[Sreekanth Narayanan]

Hello Mario,

Is the receptionist's phone an IP phone? And is the receptionist able to transfer calls to other extensions on the VG224 apart from these 3?

We would need to look at the traces for this. Is this on CUCM or CME?

Thanks

[Mario Manzano]

Hello Sreekanth!

Thanks for your response!

Yes the receptionist phone is an IP phone. They are able to transfer to other extensions on the same VG (as far as I know)

This is CME...

I gathered some traces and it appears that it is cutting it at the 3rd digit and not waiting for a fourth.

Here is the transfer section of the trace in which EXT 1602 is attempting to transfer to ext 1524 it only grabs 152 and misses the 4...

Mar 21 14:31:07.930: //2011444/FC3A8C000002/CCAPI/cc_api_call_sserv_ind:
   Interface=0x374F058, Call Id=2011444
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/RXRULE/regxrule_get_profile_from_trunkgroup_internal:
   Voice port 0x374F058 dsl=-1 timeslot=0 does not belong to any trunk group
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=1602, Called Number=, Voice-Interface=0x374F058,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOICE, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Match Rule=DP_MATCH_ANSWER; Calling Number=1602
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:
   Is Incoming=TRUE, Number Expansion=FALSE
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Dial String=, Expanded String=, Calling Number=1602T
   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Result=-1
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Match Rule=DP_MATCH_ORIGINATE; Calling Number=1602
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:
   Is Incoming=TRUE, Number Expansion=FALSE
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Dial String=, Expanded String=, Calling Number=1602T
   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:
   Result=Success(0); Incoming Dial-peer=20015 Is Matched
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=20015
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
Mar 21 14:31:07.930: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerSPI:exit@6564
1B72D956B06711E39769836A900A7ED0
Mar 21 14:37:54.344 CDT: %VOIPAAA-5-VOIP_CALL_HISTORY: CallLegType 1, ConnectionId 1B72D956B06711E39769836A900A7ED0, SetupTime 14:37:43.984 CDT Fri Mar 21 2014, PeerAddress 1698, PeerSubAddress , DisconnectCause 10  , DisconnectText normal call clearing (16), ConnectTime 14:37:54.344 CDT Fri Mar 21 2014, DisconnectTime 14:37:54.344 CDT Fri Mar 21 2014, CallOrigin 2, ChargedUnits 0, InfoType 2, TransmitPackets 0, TransmitBytes 0, ReceivePackets 0, ReceiveBytes 0
Mar 21 14:37:54.344 CDT: %VOIPAAA-5-VOIP_FEAT_HISTORY: FEAT_VSA=fn:TWC,ft:03/21/2014 14:37:43.987,cgn:1698,cdn:,frs:0,fid:2552533,fcid:1B72D956B06711E39769836A900A7ED0,legID:1EB172,bguid:1B72D956B06711E39769836A900A7ED0CCAPI/cc_get_feature_vsa:

Mar 21 14:31:07.934:  cc_get_feature_vsa count is 18
Mar 21 14:31:07.934: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:07.934: :FEATURE_VSA attributes are: feature_name:0,feature_time:168045208,feature_id:2552478
Mar 21 14:31:07.934: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

Mar 21 14:31:07.934: : Generating new featurevsa,inserting it
Mar 21 14:31:07.934: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

Mar 21 14:31:07.934:  call featname is 11
Mar 21 14:31:07.934: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

Mar 21 14:31:07.934:  feature_vsa is A042550,featname is 0
Mar 21 14:31:07.934: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:07.934: :cc_get_feature_vsa malloc success
Mar 21 14:31:07.934: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:07.934:  cc_get_feature_vsa count is 19
LegType 1, ConnectionId 236E2E2B06711E3A7C3E8B7484C88A0, SetupTime 14:37:01.664 CDT Fri Mar 21 2014, PeerAddress 8708050414, PeerSubAddress , DisconnectCause 10  , DisconnectText normal call clearing (16), ConnectTime 14:37:10.414 CDT Fri Mar 21 2014, DisconnectTime 14:38:33.144 CDT Fri Mar 21 2014, CallOrigin 2, ChargedUnits 0, InfoType 2, TransmitPackets 4116, TransmitBytes 115248, ReceivePackets 4126, ReceiveBytes 82520r 21 14:31:07.934: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Mar 21 14:31:07.934: :cc_free_feature_vsa freeing A043970
:0,fid:2552529,fcid:236E2E2B06711E3A7C3E8B7484C88A0,legID:1EB16E,bguid:0236E2E2B06711E3A7C3E8B7484C88A0 free is 18
Mar 21 14:31:07.934: //-1/2F615342970A/CCAPI/cc_api_display_ie_subfields:
   cc_api_call_setup_ind_common:
   cisco-username=
   ----- ccCallInfo IE subfields -----
   cisco-ani=1602
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=
   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

Mar 21 14:31:07.934: //-1/2F615342970A/CCAPI/cc_api_call_setup_ind_common:
   Interface=0x374F058, Call Info(
   Calling Number=1602,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=(TON=Unknown, NPI=Unknown),
   Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=FALSE,
   Incoming Dial-peer=20015, 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
Mar 21 14:31:07.934: //-1/2F615342970A/CCAPI/ccCheckClipClir:
   In: Calling Number=1602(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Mar 21 14:31:07.934: //-1/2F615342970A/CCAPI/ccCheckClipClir:
   Out: Calling Number=1602(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Mar 21 14:31:07.934: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:07.934: :cc_get_feature_vsa malloc success
Mar 21 14:31:07.934: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:07.934:  cc_get_feature_vsa count is 19
Mar 21 14:31:07.934: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:07.934: :FEATURE_VSA attributes are: feature_name:0,feature_time:168049016,feature_id:2552480
Mar 21 14:31:07.934: //2011471/2F615342970A/CCAPI/cc_api_call_setup_ind_common:
   Set Up Event Sent;
   Call Info(Calling Number=1602(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=(TON=Unknown, NPI=Unknown))
Mar 21 14:31:07.934: //-1/2F615342970A/RXRULE/regxrule_stack_pop_RegXruleNumInfo: stack=0x3CDC10C; count=1
Mar 21 14:31:07.934: //-1/2F615342970A/RXRULE/regxrule_stack_pop_callinfo_internal: numinfo=0xBEB1B7C
Mar 21 14:31:07.934: //2011471/2F615342970A/CCAPI/cc_process_call_setup_ind:
   Event=0x1B9A300
Mar 21 14:31:07.934: //2011471/2F615342970A/CCAPI/ccCallSetContext:
   Context=0x101C2CC
Mar 21 14:31:07.934: //2011471/2F615342970A/CCAPI/cc_process_call_setup_ind:
   >>>>CCAPI handed cid 2011471 with tag 20015 to app "_ManagedAppProcess_Default"
Mar 21 14:31:07.934: //-1/2F615342970A/RXRULE/regxrule_stack_push_RegXruleNumInfo_internal: stack=0x3CDC10C; count=1
Mar 21 14:31:07.934: //2011471/2F615342970A/CCAPI/ccCallSetupAck:
   Call Id=2011471
Mar 21 14:31:07.934: //2011471/2F615342970A/CCAPI/cc_api_set_transfer_info:
   Transfer Number=, Transfer Reason=0x0
Mar 21 14:31:07.934: //2011471/2F615342970A/CCAPI/ccGenerateToneInfo:
   Stop Tone On Digit=TRUE, Tone=Dial Tone,
   Tone Direction=Network, Params=0x0, Call Id=2011471
Mar 21 14:31:07.934: //2011471/2F615342970A/CCAPI/ccSetDigitTimeouts:
   Initial Digit Timeout=-1000(ms), Inter Digit Timeout=-1000(ms)
Mar 21 14:31:07.934: //2011471/2F615342970A/CCAPI/ccSetDigitTimeouts:
   Call Entry(Inter Digit Timeout=10000(ms), Initial Digit Timeout=10000(ms))
Mar 21 14:31:07.934: //2011471/2F615342970A/CCAPI/ccCallReportDigits:
   (callID=0x1EB14F, digit_event=0x1, enable=TRUE, consume=FALSE)
Mar 21 14:31:07.934: //2011471/2F615342970A/CCAPI/ccCallReportDigits:
   Enabled=TRUE, Call Id=2011471
Mar 21 14:31:07.934: //2011471/2F615342970A/CCAPI/cc_api_call_report_digits_done:
   (vdbPtr=0x374F058, callID=0x1EB14F, disp=0, digit_event=0x1, enable=TRUE, consume=FALSE)
Mar 21 14:31:07.934: //2011471/2F615342970A/CCAPI/cc_api_call_report_digits_done:
   Enabled=TRUE, Disposition=0x0, Interface=0x374F058, Call Id=2011471
Mar 21 14:31:07.934: //2011471/2F615342970A/CCAPI/cc_api_call_report_digits_done:
   Call Entry(Initial Digit Timeout=15000(ms), Inter Digit Timeout=10000(ms))
Mar 21 14:31:08.490: //2011471/2F615342970A/CCAPI/cc_api_call_digit_begin:
   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
   Source Call Id=2011471, Digit=1, DigitBeginFlags=0x0,
   Rtp Timestamp=0x3AE2FF38, Rtp Expiration=0x0
Mar 21 14:31:08.490: //2011471/2F615342970A/CCAPI/cc_api_call_digit_end:
   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
   Source Call Id=2011471, Digit=1, Duration=100,
   Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
Mar 21 14:31:08.490: //2011471/2F615342970A/CCAPI/cc_api_call_digit_end:
   Call Entry(Handoff Depth=0)
Mar 21 14:31:08.490: //-1/2F615342970A/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=1, Peer Info Type=DIALPEER_INFO_SPEECH
Mar 21 14:31:08.490: //-1/2F615342970A/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=1
Mar 21 14:31:08.490: //-1/2F615342970A/DPM/dpMatchCore:
   Dial String=1, Expanded String=1, Calling Number=
   Timeout=FALSE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH
Mar 21 14:31:08.494: //-1/2F615342970A/DPM/MatchNextPeer:
   Result=MORE_DIGITS_NEEDED(1); Outgoing Dial-peer=2020
Mar 21 14:31:08.494: //-1/2F615342970A/DPM/dpMatchCore:
   Result=1
Mar 21 14:31:08.494: //-1/2F615342970A/DPM/dpMatchPeersCore:
   Result=Partial Matches(1) after DP_MATCH_DEST
Mar 21 14:31:08.494: //-1/2F615342970A/DPM/dpMatchSafModulePlugin:
   dialstring=1, saf_enabled=1, saf_dndb_lookup=0, dp_result=1
Mar 21 14:31:08.494: //-1/2F615342970A/DPM/dpMatchPeersMoreArg:
   Result=MORE_DIGITS_NEEDED(1)
Mar 21 14:31:09.282: //2011471/2F615342970A/CCAPI/cc_api_call_digit_begin:
   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
   Source Call Id=2011471, Digit=5, DigitBeginFlags=0x0,
   Rtp Timestamp=0x3AE37C38, Rtp Expiration=0x0
Mar 21 14:31:09.282: //2011471/2F615342970A/CCAPI/cc_api_call_digit_end:
   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
   Source Call Id=2011471, Digit=5, Duration=100,
   Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
Mar 21 14:31:09.282: //2011471/2F615342970A/CCAPI/cc_api_call_digit_end:
   Call Entry(Handoff Depth=0)
Mar 21 14:31:09.286: //-1/2F615342970A/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=15, Peer Info Type=DIALPEER_INFO_SPEECH
Mar 21 14:31:09.286: //-1/2F615342970A/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=15
Mar 21 14:31:09.286: //-1/2F615342970A/DPM/dpMatchCore:
   Dial String=15, Expanded String=15, Calling Number=
   Timeout=FALSE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH
Mar 21 14:31:09.286: //-1/2F615342970A/DPM/MatchNextPeer:
   Result=MORE_DIGITS_NEEDED(1); Outgoing Dial-peer=85011537
Mar 21 14:31:09.286: //-1/2F615342970A/DPM/dpMatchCore:
   Result=1
Mar 21 14:31:09.286: //-1/2F615342970A/DPM/dpMatchPeersCore:
   Result=Partial Matches(1) after DP_MATCH_DEST
Mar 21 14:31:09.286: //-1/2F615342970A/DPM/dpMatchSafModulePlugin:
   dialstring=15, saf_enabled=1, saf_dndb_lookup=0, dp_result=1
Mar 21 14:31:09.286: //-1/2F615342970A/DPM/dpMatchPeersMoreArg:
   Result=MORE_DIGITS_NEEDED(1)
Mar 21 14:31:09.546: //2011471/2F615342970A/CCAPI/cc_api_call_digit_begin:
   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
   Source Call Id=2011471, Digit=2, DigitBeginFlags=0x0,
   Rtp Timestamp=0x3AE3F938, Rtp Expiration=0x0
Mar 21 14:31:09.546: //2011471/2F615342970A/CCAPI/cc_api_call_digit_end:
   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
   Source Call Id=2011471, Digit=2, Duration=100,
   Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
Mar 21 14:31:09.546: //2011471/2F615342970A/CCAPI/cc_api_call_digit_end:
   Call Entry(Handoff Depth=0)
Mar 21 14:31:09.546: //-1/2F615342970A/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=152, Peer Info Type=DIALPEER_INFO_SPEECH
Mar 21 14:31:09.546: //-1/2F615342970A/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=152
Mar 21 14:31:09.546: //-1/2F615342970A/DPM/dpMatchCore:
   Dial String=152, Expanded String=152, Calling Number=
   Timeout=FALSE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH
Mar 21 14:31:09.546: //-1/2F615342970A/DPM/MatchNextPeer:
   Result=MORE_DIGITS_NEEDED(1); Outgoing Dial-peer=85011526
Mar 21 14:31:09.546: //-1/2F615342970A/DPM/dpMatchCore:
   Result=1
Mar 21 14:31:09.546: //-1/2F615342970A/DPM/dpMatchPeersCore:
   Result=Partial Matches(1) after DP_MATCH_DEST
Mar 21 14:31:09.546: //-1/2F615342970A/DPM/dpMatchSafModulePlugin:
   dialstring=152, saf_enabled=1, saf_dndb_lookup=0, dp_result=1
Mar 21 14:31:09.546: //-1/2F615342970A/DPM/dpMatchPeersMoreArg:
   Result=MORE_DIGITS_NEEDED(1)
Mar 21 14:31:12.951: //2011471/2F615342970A/CCAPI/cc_api_call_disconnected:
   Cause Value=16, Interface=0x374F058, Call Id=2011471
Mar 21 14:31:12.951: //2011471/2F615342970A/CCAPI/cc_api_call_disconnected:
   Call Entry(Responsed=FALSE, Cause Value=16, Retry Count=0)
Mar 21 14:31:12.951: //2011471/2F615342970A/CCAPI/ccCallDisconnect:
   Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=16)
Mar 21 14:31:12.951: //2011471/2F615342970A/CCAPI/ccCallDisconnect:
   Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
Mar 21 14:31:12.951: //2011471/2F615342970A/CCAPI/cc_api_get_transfer_info:
   Transfer Number Is Null
Mar 21 14:31:12.951 CDT: %VOIPAAA-5-VOIP_CALL_HISTORY: CallLegType 1, ConnectionId 2F615342B06611E3970A836A900A7ED0, SetupTime 14:31:07.941 CDT Fri Mar 21 2014, PeerAddress 1602, PeerSubAddress , DisconnectCause 10  , DisconnectText normal call clearing (16), ConnectTime 14:31:12.951 CDT Fri Mar 21 2014, DisconnectTime 14:31:12.951 CDT Fri Mar 21 2014, CallOrigin 2, ChargedUnits 0, InfoType 2, TransmitPackets 0, TransmitBytes 0, ReceivePackets 0, ReceiveBytes 0
Mar 21 14:31:12.951: //-1/xxxxxxxxxxxx/CCAPI/cc_build_feature_vsa:

Mar 21 14:31:12.951: :Inside cc_build_feature_vsa
Mar 21 14:31:12.951: //-1/xxxxxxxxxxxx/CCAPI/cc_build_feature_vsa:

Mar 21 14:31:12.951:  feature call basic
Mar 21 14:31:12.951: //-1/xxxxxxxxxxxx/CCAPI/cc_build_feature_vsa:

Mar 21 14:31:12.951: cc_build_feature_vsa attr is fn:TWC,ft:03/21/2014 14:31:07.934,cgn:1602,cdn:,frs:0,fid:2552480,fcid:2F615342B06611E3970A836A900A7ED0,legID:1EB14F
Mar 21 14:31:12.951 CDT: %VOIPAAA-5-VOIP_FEAT_HISTORY: FEAT_VSA=fn:TWC,ft:03/21/2014 14:31:07.934,cgn:1602,cdn:,frs:0,fid:2552480,fcid:2F615342B06611E3970A836A900A7ED0,legID:1EB14F,bguid:2F615342B06611E3970A836A900A7ED0
Mar 21 14:31:12.951: //2011471/2F615342970A/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x374F058, Tag=0x0, Call Id=2011471,
   Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
Mar 21 14:31:12.951: //-1/2F615342970A/RXRULE/regxrule_stack_pop_RegXruleNumInfo: stack=0x3CDC10C; count=1
Mar 21 14:31:12.951: //-1/2F615342970A/RXRULE/regxrule_stack_pop_callinfo_internal: numinfo=0xBEB1B7C
Mar 21 14:31:12.951: //2011471/2F615342970A/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
Mar 21 14:31:12.951: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Mar 21 14:31:12.951: :cc_free_feature_vsa freeing A043970
Mar 21 14:31:12.951: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Mar 21 14:31:12.951:  vsacount in free is 18
Mar 21 14:31:14.287: //2011444/FC3A8C000002/CCAPI/cc_api_call_sserv_ind:
   Interface=0x374F058, Call Id=2011444
Mar 21 14:31:14.287: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=1602, Peer Info Type=DIALPEER_INFO_SPEECH
Mar 21 14:31:14.287: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=1602
Mar 21 14:31:14.287: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Dial String=1602, Expanded String=1602, Calling Number=
   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH
Mar 21 14:31:14.287: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:
   Result=Success(0); Outgoing Dial-peer=20015 Is Matched
Mar 21 14:31:14.287: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
Mar 21 14:31:14.287: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=1602, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
Mar 21 14:31:14.287: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=20015
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:14.291: :cc_get_feature_vsa malloc success
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:14.291:  cc_get_feature_vsa count is 19
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:14.291: :FEATURE_VSA attributes are: feature_name:0,feature_time:168049016,feature_id:2552481
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

Mar 21 14:31:14.291:  feature_vsa is A042A90,featname is 11
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

Mar 21 14:31:14.291:  feature_vsa is A0413D0,featname is 0
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:14.291: :cc_get_feature_vsa malloc success
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:14.291:  cc_get_feature_vsa count is 20
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:14.291: :FEATURE_VSA attributes are: feature_name:0,feature_time:168041176,feature_id:2552482
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

Mar 21 14:31:14.291: : Generating new featurevsa,inserting it
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

Mar 21 14:31:14.291:  call featname is 12
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

Mar 21 14:31:14.291:  feature_vsa is A041130,featname is 11
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

Mar 21 14:31:14.291:  feature_vsa is A042550,featname is 0
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:14.291: :cc_get_feature_vsa malloc success
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:14.291:  cc_get_feature_vsa count is 21
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 21 14:31:14.291: :FEATURE_VSA attributes are: feature_name:0,feature_time:168044536,feature_id:2552483
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

Mar 21 14:31:14.291: : Generating new featurevsa,inserting it
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

Mar 21 14:31:14.291:  call featname is 12
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Mar 21 14:31:14.291: :cc_free_feature_vsa freeing A043970
Mar 21 14:31:14.291: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Mar 21 14:31:14.291:  vsacount in free is 20

[Brian Meade]

What do you have configured for the transfer-pattern under telephony-service config?  What do your dial-peers look like?

[Mario Manzano]

Hello Brian!

thanks for your time!

We have an extensive list of DP on that particular router, but there is one specific for each of the particular extensions that do not work... see config section below:

telephony-service
 sdspfarm conference mute-on *0 mute-off *0
 sdspfarm units 4
 sdspfarm tag 1 mtpe8b748c88a0
 conference hardware
 no auto-reg-ephone
 authentication credential admin tek1links
 max-ephones 150
 max-dn 500
 ip source-address 10.31.100.1 port 2000
 system message Peco Foods
 url services http://10.31.100.2/voiceview/common/login.do
 url authentication http://10.31.100.1/CCMCIP/authenticate.asp
 cnf-file location flash:
 cnf-file perphone
 load 7915-24 B015-1-0-4
 load 7937 cmterm-7937-1-4-3-SCCP.cop
 load 7942 SCCP42.9-1-1SR1S
 load 7945 SCCP45.9-1-1SR1S
 load 7962 SCCP42.9-1-1SR1S
 load 7965 SCCP45.9-1-1SR1S
 time-zone 8
 live-record 7999
 voicemail 1710
 max-conferences 8 gain -6
 moh music-on-hold.au
 web admin system name teklinks password tek1links
 dn-webedit
 time-webedit
 transfer-system full-consult dss
 transfer-pattern 9T
 secondary-dialtone 9
 night-service code *66
 create cnf-files version-stamp Jan 01 2002 00:00:00

dial-peer voice 85011524 voip
 destination-pattern 1524
 session target ipv4:10.51.100.11
 codec g711ulaw
 no vad

[Brian Meade]

The transfer pattern of 9T is kind of strange.  Looks like you can only really transfer to numbers beginning with 9.  But also what's weird is it looks like it's matching dial-peer 85011526 from the debugs.  How is that dial-peer configured?