SIP Trunk works outbound to CME, not inbound to CUCM

[ken.montgomery]

Hi Everyone,

I've been struggling with this for a while now, gave up on the h323 connectivity and went back to SIP.  Here is the scenario:  We have a Cisco Unified Communication Manager 6.1 system in one office, which is up and running and working fine.  This system uses 4-digit dialing for internal extensions, all starting with 7XXX.  We also have a CME running at a remote location, all extensions 8XXX.  All is working fine there as well.  We have an MPLS network between the two, and IP connectivity is solid and easily visible. 

Now, What I'm trying to do is allow users at the main site to call the remote site using 228xxx, which is working.  This is across SIP trunk to remote site.  The remote site should be able to dial 217xxx and get the 4-digit extension at HQ.  I see the SIP invites go out, yet the calls never go through.  I'm struggling to find a cause in the CUCM that is denying the call...

The CME Relevant configurations:

Current configuration : 49762 bytes

voice service voip

ip address trusted list

  ipv4 10.96.178.0 255.255.255.0

  ipv4 <CUCM-Primary>

  ipv4 <CUCM-Secondary>

allow-connections h323 to h323

allow-connections h323 to sip

allow-connections sip to sip

no supplementary-service sip moved-temporarily

no supplementary-service sip refer

fax protocol t38 version 0 ls-redundancy 0 hs-redundancy 0 fallback none

h323

  h245 signal update

sip

  registrar server expires max 3600 min 3600

voice translation-rule 10

rule 10 /^21/ //

!

voice translation-rule 11

rule 11 /^22/ //

!

!

voice translation-profile CUCM-INBOUND

translate called 11

!

voice translation-profile CUCM-OUTBOUND

translate calling 10

translate called 10

!

!

dial-peer voice 210 voip

description *** OUTBOUND to CUCM CALL MANAGER TEST ***

translation-profile outgoing CUCM-OUTBOUND

destination-pattern 21....

session protocol sipv2

session target ipv4:<CUCM-Subscriber>

voice-class codec 1

voice-class sip dtmf-relay force rtp-nte

dtmf-relay rtp-nte

no vad

!

dial-peer voice 211 voip

description *** INCOMING CALLS FROM CUCM ****

group-name FairlawnIncoming

destination-pattern 8...

session target ipv4:<CUCM-Subscriber>

incoming called-number .

voice-class codec 1

voice-class sip dtmf-relay force rtp-nte

dtmf-relay rtp-nte

no vad

!

sip-ua

no remote-party-id

retry invite 2

retry register 10

timers connect 100

host-registrar

!

telephony-service

no auto-reg-ephone

authentication credential cmeadmin d3l3m@

max-ephones 95

max-dn 95

ip source-address <CME IP Address> port 2000

timeouts interdigit 3

timeouts ringing 20

system message VEYANCE

time-zone 43

voicemail 7999

max-conferences 8 gain -6

call-forward pattern 4....

moh "flash:music-on-hold.au"

dn-webedit

time-webedit

transfer-system full-consult

secondary-dialtone 9

create cnf-files version-stamp 7960 Aug 20 2012 21:17:28

Call Manager has a SIP Trunk setup with a separate device pool, Call Classification "On Net"

Again, outbound calls to the CME work fine.  Inbound from CME to CUCM do not work at all... here is a test, dialing 217163 on the CME:

I am running this with the following debugs enabled:

DIALPEER:

  debug voip dialpeer detail is ON (filter is OFF)

CCAPI:

  debug voip ccapi inout is ON (filter is OFF)

CCSIP SPI: SIP Call Statistics tracing is enabled       (filter is OFF)

CCSIP SPI: SIP Call Events tracing is enabled   (filter is OFF)

Here is the debug output from call from 8500 to 217163:

Mar 11 17:35:43.334: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_ANSWER; Calling Number=8500

Mar 11 17:35:43.334: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Mar 11 17:35:43.334: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=8500T

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:43.334: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Result=-1

Mar 11 17:35:43.334: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_ORIGINATE; Calling Number=8500

Mar 11 17:35:43.334: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Mar 11 17:35:43.334: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=8500T

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:43.334: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:

   Result=Success(0); Incoming Dial-peer=211 Is Matched

Mar 11 17:35:43.334: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:

   Result=Success(0); Incoming Dial-peer=20096 Is Matched

Mar 11 17:35:43.334: //-1/EF178EEE90B5/CCAPI/cc_api_display_ie_subfields:

   cc_api_call_setup_ind_common:

   cisco-username=

   ----- ccCallInfo IE subfields -----

   cisco-ani=8500

   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 11 17:35:43.334: //-1/EF178EEE90B5/CCAPI/cc_api_call_setup_ind_common:

   Interface=0x1CA10704, Call Info(

   Calling Number=8500,(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=20096, 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 11 17:35:43.334: //-1/EF178EEE90B5/CCAPI/ccCheckClipClir:

   In: Calling Number=8500(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)

Mar 11 17:35:43.334: //-1/EF178EEE90B5/CCAPI/ccCheckClipClir:

   Out: Calling Number=8500(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)

Mar 11 17:35:43.334: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 11 17:35:43.334: :cc_get_feature_vsa malloc success

Mar 11 17:35:43.334: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 11 17:35:43.334:  cc_get_feature_vsa count is 1

Mar 11 17:35:43.334: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 11 17:35:43.334: :FEATURE_VSA attributes are: feature_name:0,feature_time:504015312,feature_id:147573

Mar 11 17:35:43.334: //775709/EF178EEE90B5/CCAPI/cc_api_call_setup_ind_common:

   Set Up Event Sent;

   Call Info(Calling Number=8500(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),

   Called Number=(TON=Unknown, NPI=Unknown))

Mar 11 17:35:43.334: //775709/EF178EEE90B5/CCAPI/cc_process_call_setup_ind:

   Event=0x1620BED0

Mar 11 17:35:43.334: //775709/EF178EEE90B5/CCAPI/ccCallSetContext:

   Context=0x117C92D4

Mar 11 17:35:43.334: //775709/EF178EEE90B5/CCAPI/cc_process_call_setup_ind:

   >>>>CCAPI handed cid 775709 with tag 20096 to app "_ManagedAppProcess_Default"

Mar 11 17:35:43.334: //775709/EF178EEE90B5/CCAPI/ccCallSetupAck:

   Call Id=775709

Mar 11 17:35:43.334: //775709/EF178EEE90B5/CCAPI/cc_api_set_transfer_info:

   Transfer Number=, Transfer Reason=0x0

Mar 11 17:35:43.334: //775709/EF178EEE90B5/CCAPI/ccGenerateToneInfo:

   Stop Tone On Digit=TRUE, Tone=Dial Tone,

   Tone Direction=Network, Params=0x0, Call Id=775709

Mar 11 17:35:43.338: //775709/EF178EEE90B5/CCAPI/ccSetDigitTimeouts:

   Initial Digit Timeout=-1000(ms), Inter Digit Timeout=-1000(ms)

Mar 11 17:35:43.338: //775709/EF178EEE90B5/CCAPI/ccSetDigitTimeouts:

   Call Entry(Inter Digit Timeout=10000(ms), Initial Digit Timeout=10000(ms))

Mar 11 17:35:43.338: //775709/EF178EEE90B5/CCAPI/ccCallReportDigits:

   (callID=0xBD61D, digit_event=0x1, enable=TRUE, consume=FALSE)

Mar 11 17:35:43.338: //775709/EF178EEE90B5/CCAPI/ccCallReportDigits:

   Enabled=TRUE, Call Id=775709

Mar 11 17:35:43.338: //775709/EF178EEE90B5/CCAPI/cc_api_call_report_digits_done:

   (vdbPtr=0x1CA10704, callID=0xBD61D, disp=0, digit_event=0x1, enable=TRUE, consume=FALSE)

Mar 11 17:35:43.338: //775709/EF178EEE90B5/CCAPI/cc_api_call_report_digits_done:

   Enabled=TRUE, Disposition=0x0, Interface=0x1CA10704, Call Id=775709

Mar 11 17:35:43.338: //775709/EF178EEE90B5/CCAPI/cc_api_call_report_digits_done:

   Call Entry(Initial Digit Timeout=15000(ms), Inter Digit Timeout=3000(ms))

Mar 11 17:35:43.538: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_begin:

   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,

   Source Call Id=775709, Digit=2, DigitBeginFlags=0x0,

   Rtp Timestamp=0x21493D8, Rtp Expiration=0x0

Mar 11 17:35:43.538: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_end:

   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,

   Source Call Id=775709, Digit=2, Duration=100,

   Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF

Mar 11 17:35:43.538: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_end:

   Call Entry(Handoff Depth=0)

Mar 11 17:35:43.538: //-1/EF178EEE90B5/DPM/dpMatchCore:

Veyance_CME#Dial String=2, Expanded String=2, Calling Number=

   Timeout=FALSE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:43.538: //-1/EF178EEE90B5/DPM/MatchNextPeer:

   Result=MORE_DIGITS_NEEDED(1); Outgoing Dial-peer=210

Mar 11 17:35:43.538: //-1/EF178EEE90B5/DPM/dpMatchCore:

   Result=1

Mar 11 17:35:43.738: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_begin:

   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,

   Source Call Id=775709, Digit=1, DigitBeginFlags=0x0,

   Rtp Timestamp=0x21510D8, Rtp Expiration=0x0

Mar 11 17:35:43.738: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_end:

   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,

   Source Call Id=775709, Digit=1, Duration=100,

   Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF

Mar 11 17:35:43.738: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_end:

   Call Entry(Handoff Depth=0)

Mar 11 17:35:43.738: //-1/EF178EEE90B5/DPM/dpMatchCore:

   Dial String=21, Expanded String=21, Calling Number=

   Timeout=FALSE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:43.738: //-1/EF178EEE90B5/DPM/MatchNextPeer:

   Result=MORE_DIGITS_NEEDED(1); Outgoing Dial-peer=210

Mar 11 17:35:43.738: //-1/EF178EEE90B5/DPM/dpMatchCore:

   Result=1

Mar 11 17:35:43.938: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_begin:

   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,

   Source Call Id=775709, Digit=7, DigitBeginFlags=0x0,

   Rtp Timestamp=0x2158DD8, Rtp Expiration=0x0

Mar 11 17:35:43.938: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_end:

   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,

   Source Call Id=775709, Digit=7, Duration=100,

   Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF

Mar 11 17:35:43.938: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_end:

   Call Entry(Handoff Depth=0)

Mar 11 17:35:43.938: //-1/EF178EEE90B5/DPM/dpMatchCore:

   Dial String=217, Expanded String=217, Calling Number=

   Timeout=FALSE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:43.938: //-1/EF178EEE90B5/DPM/MatchNextPeer:

   Result=MORE_DIGITS_NEEDED(1); Outgoing Dial-peer=210

Mar 11 17:35:43.938: //-1/EF178EEE90B5/DPM/dpMatchCore:

   Result=1

Mar 11 17:35:44.138: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_begin:

   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,

   Source Call Id=775709, Digit=1, DigitBeginFlags=0x0,

   Rtp Timestamp=0x2160AD8, Rtp Expiration=0x0

Mar 11 17:35:44.138: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_end:

   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,

   Source Call Id=775709, Digit=1, Duration=100,

   Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF

Mar 11 17:35:44.138: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_end:

   Call Entry(Handoff Depth=0)

Mar 11 17:35:44.138: //-1/EF178EEE90B5/DPM/dpMatchCore:

   Dial String=2171, Expanded String=2171, Calling Number=

   Timeout=FALSE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:44.138: //-1/EF178EEE90B5/DPM/MatchNextPeer:

   Result=MORE_DIGITS_NEEDED(1); Outgoing Dial-peer=210

Mar 11 17:35:44.138: //-1/EF178EEE90B5/DPM/dpMatchCore:

   Result=1

Mar 11 17:35:44.338: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_begin:

   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,

   Source Call Id=775709, Digit=6, DigitBeginFlags=0x0,

   Rtp Timestamp=0x21687D8, Rtp Expiration=0x0

Mar 11 17:35:44.338: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_end:

   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,

   Source Call Id=775709, Digit=6, Duration=100,

   Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF

Mar 11 17:35:44.338: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_end:

   Call Entry(Handoff Depth=0)

Mar 11 17:35:44.338: //-1/EF178EEE90B5/DPM/dpMatchCore:

   Dial String=21716, Expanded String=21716, Calling Number=

   Timeout=FALSE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:44.338: //-1/EF178EEE90B5/DPM/MatchNextPeer:

   Result=MORE_DIGITS_NEEDED(1); Outgoing Dial-peer=210

Mar 11 17:35:44.338: //-1/EF178EEE90B5/DPM/dpMatchCore:

   Result=1

Mar 11 17:35:44.538: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_begin:

   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,

   Source Call Id=775709, Digit=3, DigitBeginFlags=0x0,

   Rtp Timestamp=0x21704D8, Rtp Expiration=0x0

Mar 11 17:35:44.538: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_end:

   Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,

   Source Call Id=775709, Digit=3, Duration=100,

   Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF

Mar 11 17:35:44.538: //775709/EF178EEE90B5/CCAPI/cc_api_call_digit_end:

   Call Entry(Handoff Depth=0)

Mar 11 17:35:44.538: //-1/EF178EEE90B5/DPM/dpMatchCore:

   Dial String=217163, Expanded String=217163, Calling Number=

   Timeout=FALSE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:44.538: //-1/EF178EEE90B5/DPM/MatchNextPeer:

   Result=Success(0); Outgoing Dial-peer=210 Is Matched

Mar 11 17:35:44.538: //775709/EF178EEE90B5/CCAPI/ccCallReportDigits:

   (callID=0xBD61D, digit_event=0x0, enable=FALSE, consume=FALSE)

Mar 11 17:35:44.538: //775709/EF178EEE90B5/CCAPI/ccCallReportDigits:

   Enabled=TRUE, Call Id=775709

Mar 11 17:35:44.538: //775709/EF178EEE90B5/CCAPI/cc_api_call_report_digits_done:

   (vdbPtr=0x1CA10704, callID=0xBD61D, disp=0, digit_event=0x0, enable=FALSE, consume=FALSE)

Mar 11 17:35:44.538: //775709/EF178EEE90B5/CCAPI/cc_api_call_report_digits_done:

   Enabled=TRUE, Disposition=0x0, Interface=0x1CA10704, Call Id=775709

Mar 11 17:35:44.538: //775709/EF178EEE90B5/CCAPI/cc_api_call_report_digits_done:

   Call Entry(Initial Digit Timeout=15000(ms), Inter Digit Timeout=3000(ms))

Mar 11 17:35:44.538: //775709/EF178EEE90B5/CCAPI/ccCallProceeding:

   Progress Indication=NULL(0)

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_ANSWER; Calling Number=8500

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=8500T

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Result=-1

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_ORIGINATE; Calling Number=8500

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=8500T

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:

   Result=Success(0); Incoming Dial-peer=211 Is Matched

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:

   Result=Success(0); Incoming Dial-peer=20096 Is Matched

Mar 11 17:35:44.538: //-1/EF178EEE90B5/DPM/dpMatchCore:

   Dial String=217163, Expanded String=217163, Calling Number=

   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:44.538: //-1/EF178EEE90B5/DPM/MatchNextPeer:

   Result=Success(0); Outgoing Dial-peer=210 Is Matched

Mar 11 17:35:44.538: //-1/EF178EEE90B5/DPM/dpMatchCore:

   Dial String=217163, Expanded String=217163, Calling Number=

   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:44.538: //-1/EF178EEE90B5/DPM/MatchNextPeer:

   Result=Success(0); Outgoing Dial-peer=210 Is Matched

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=217163, Expanded String=217163, Calling Number=217163T

   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:

   Result=Success(0); Outgoing Dial-peer=210 Is Matched

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_ANSWER; Calling Number=217163

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=217163T

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Result=-1

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_ORIGINATE; Calling Number=217163

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=217163T

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:

   Result=Success(0); Incoming Dial-peer=210 Is Matched

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=217163, Expanded String=217163, Calling Number=

   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:44.538: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:

   Result=Success(0); Outgoing Dial-peer=210 Is Matched

Mar 11 17:35:44.538: //-1/EF178EEE90B5/DPM/dpMatchCore:

   Dial String=217163, Expanded String=217163, Calling Number=

   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Mar 11 17:35:44.538: //-1/EF178EEE90B5/DPM/MatchNextPeer:

   Result=Success(0); Outgoing Dial-peer=210 Is Matched

Mar 11 17:35:44.538: //775709/EF178EEE90B5/CCAPI/ccCallSetupRequest:

   Destination=, Calling IE Present=TRUE, Mode=0,

   Outgoing Dial-peer=210, Params=0x3AFB7F8, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)

Mar 11 17:35:44.538: //775709/EF178EEE90B5/CCAPI/ccCheckClipClir:

   In: Calling Number=8500(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)

Mar 11 17:35:44.538: //775709/EF178EEE90B5/CCAPI/ccCheckClipClir:

   Out: Calling Number=8500(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)

Mar 11 17:35:44.538: //775709/EF178EEE90B5/CCAPI/ccCallSetupRequest:

   Destination Pattern=21...., Called Number=7163, Digit Strip=FALSE

Mar 11 17:35:44.538: //775709/EF178EEE90B5/CCAPI/ccCallSetupRequest:

   Calling Number=8500(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),

   Called Number=7163(TON=Unknow

Veyance_CME#n, NPI=Unknown),

   Redirect Number=, Display Info=Testing

   Account Number=, Final Destination Flag=FALSE,

   Guid=EF178EEE-89A8-11E2-90B5-9DDB61BF2B12, Outgoing Dial-peer=210

Mar 11 17:35:44.542: //775709/EF178EEE90B5/CCAPI/cc_api_display_ie_subfields:

   ccCallSetupRequest:

   cisco-username=

   ----- ccCallInfo IE subfields -----

   cisco-ani=8500

   cisco-anitype=0

   cisco-aniplan=0

   cisco-anipi=0

   cisco-anisi=0

   dest=7163

   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 11 17:35:44.542: //775709/EF178EEE90B5/CCAPI/ccIFCallSetupRequestPrivate:

   Interface=0x24701AC, Interface Type=3, Destination=, Mode=0x0,

   Call Params(Calling Number=8500,(Calling Name=Testing)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),

   Called Number=7163(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,

   Subscriber Type Str=RegularLine, FinalDestinationFlag=FALSE, Outgoing Dial-peer=210, Call Count On=FALSE,

   Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)

Mar 11 17:35:44.542: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 11 17:35:44.542: :cc_get_feature_vsa malloc success

Mar 11 17:35:44.542: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 11 17:35:44.542:  cc_get_feature_vsa count is 2

Mar 11 17:35:44.542: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 11 17:35:44.542: :FEATURE_VSA attributes are: feature_name:0,feature_time:504012176,feature_id:147574

Mar 11 17:35:44.542: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_SETUP

Mar 11 17:35:44.542: //775710/EF178EEE90B5/CCAPI/ccIFCallSetupRequestPrivate:

   SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1

Mar 11 17:35:44.542: //775710/EF178EEE90B5/CCAPI/ccCallSetContext:

   Context=0x3AFB7A8

Mar 11 17:35:44.542: //775709/EF178EEE90B5/CCAPI/ccSaveDialpeerTag:

   Outgoing Dial-peer=210

Mar 11 17:35:44.542: //775710/EF178EEE90B5/CCAPI/cc_api_call_proceeding:

   Interface=0x24701AC, Progress Indication=NULL(0)

Mar 11 17:35:44.542: //775710/EF178EEE90B5/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ

Mar 11 17:35:44.542: //775710/EF178EEE90B5/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:0, container:154D2CFC

Mar 11 17:35:44.878: //775710/EF178EEE90B5/CCAPI/cc_api_call_disconnected:

   Cause Value=63, Interface=0x24701AC, Call Id=775710

Mar 11 17:35:44.878: //775710/EF178EEE90B5/CCAPI/cc_api_call_disconnected:

   Call Entry(Responsed=TRUE, Cause Value=63, Retry Count=0)

Mar 11 17:35:44.878: //775709/EF178EEE90B5/CCAPI/ccCallReleaseResources:

   release reserved xcoding resource.

Mar 11 17:35:44.878: //775710/EF178EEE90B5/CCAPI/ccCallSetAAA_Accounting:

   Accounting=0, Call Id=775710

Mar 11 17:35:44.878: //775710/EF178EEE90B5/CCAPI/ccCallDisconnect:

   Cause Value=63, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=63)

Mar 11 17:35:44.878: //775710/EF178EEE90B5/CCAPI/ccCallDisconnect:

   Cause Value=63, Call Entry(Responsed=TRUE, Cause Value=63)

Mar 11 17:35:44.878: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT

Mar 11 17:35:44.878: //775710/EF178EEE90B5/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SPI_EVENT

Mar 11 17:35:44.878: //775710/EF178EEE90B5/CCAPI/cc_api_call_disconnect_done:

   Disposition=0, Interface=0x24701AC, Tag=0x0, Call Id=775710,

   Call Entry(Disconnect Cause=63, Voice Class Cause Code=0, Retry Count=0)

Mar 11 17:35:44.878: //775710/EF178EEE90B5/CCAPI/cc_api_call_disconnect_done:

   Call Disconnect Event Sent

Mar 11 17:35:44.878: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Mar 11 17:35:44.878: :cc_free_feature_vsa freeing 1E0A9D88

Mar 11 17:35:44.878: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Mar 11 17:35:44.878:  vsacount in free is 1

Mar 11 17:35:44.878: //775710/EF178EEE90B5/SIP/Call/sipSPICallInfo:

The Call Setup Information is:

Call Control Block (CCB) : 0x0x166A6DC8

State of The Call        : STATE_DEAD

TCP Sockets Used         : NO

Calling Number           : 8500

Called Number            : 7163

Source IP Address (Sig  ): 10.96.178.2

Destn SIP Req Addr:Port  : 10.96.210.2:5060

Destn SIP Resp Addr:Port : 10.96.210.2:5060

Destination Name         : 10.96.210.2

Mar 11 17:35:44.878: //775710/EF178EEE90B5/SIP/Call/sipSPIMediaCallInfo:

Number of Media Streams: 1

Media Stream             : 1

Negotiated Codec         : No Codec

Negotiated Codec Bytes   : 0

Nego. Codec payload      : 255 (tx), 255 (rx)

Negotiated Dtmf-relay    : 0

Dtmf-relay Payload       : 0 (tx), 0 (rx)

Source IP Address (Media): 10.96.178.2

Source IP Port    (Media): 29942

Destn  IP Address (Media):  -

Destn  IP Port    (Media): 0

Orig Destn IP Address:Port (Media): [ - ]:0

Mar 11 17:35:44.878: //775710/EF178EEE90B5/SIP/Call/sipSPICallInfo:

Disconnect Cause (CC)    : 63

Disconnect Cause (SIP)   : 503

Veyance_CME#

Mar 11 17:35:44.878: //775709/EF178EEE90B5/CCAPI/ccCallDisconnect:

   Cause Value=63, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)

Mar 11 17:35:44.878: //775709/EF178EEE90B5/CCAPI/ccCallDisconnect:

   Cause Value=63, Call Entry(Responsed=TRUE, Cause Value=63)

Mar 11 17:35:44.878: //775709/EF178EEE90B5/CCAPI/cc_api_get_transfer_info:

   Transfer Number=NULL

Veyance_CME#

Mar 11 17:35:46.306: //775709/EF178EEE90B5/CCAPI/cc_api_call_disconnect_done:

   Disposition=0, Interface=0x1CA10704, Tag=0x0, Call Id=775709,

   Call Entry(Disconnect Cause=63, Voice Class Cause Code=0, Retry Count=0)

Mar 11 17:35:46.306: //775709/EF178EEE90B5/CCAPI/cc_api_call_disconnect_done:

   Call Disconnect Event Sent

Mar 11 17:35:46.306: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Mar 11 17:35:46.306: :cc_free_feature_vsa freeing 1E0AA9C8

Mar 11 17:35:46.306: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Mar 11 17:35:46.306:  vsacount in free is 0

In previous debugs, I did come across a SIP/2.0 503 error as well, but not at this time...

Any help/suggestions are appreciated.

[ken.montgomery]

Made no difference.

[ken.montgomery]

Ok, the phone is registered through the CME as a Cisco Ip Communicator phone, but when it attempts to call the CUCm, it appears to act as if it comes from the sip provider.  Why is that?

[daniel.bloom]

It looks like you are using the same interface for both the Skype and CUCM sip calls? If this is the case then bindings are not going to be a problem. As a test you could use a sip profile on your outbound dialpeer to CUCM to replace the sip provider information in the from header with the IP address of the cme router. Something like

voice class sip-profiles 100
request INVITE sip-header From modify "" ""

dial-peer voice xxx voip
voice-class sip-profiles 100

Use this website for more info on sip profiles
http://www.cisco.com/en/US/products/sw/voicesw/ps5640/products_configuration_example09186a0080982499.shtml#steps

Back on the calling search space suggestion, the sip trunk uses the calling search space assigned to determine where inbound calls to the sip trunk are allowed to be routed. Therefore if the 7xxx extension reside in a partition on CUCM the sip trunk will need a calling search space that has that same partition included in it.


Sent from Cisco Technical Support iPad App

[ken.montgomery]

In regards to the calling search space, one was previously created and is still in use.  I haven't stopped using it, so I don't know that it is the problem, unless I'm not understanding what you mean. 

I'm a little fuzzy on what you are asking for regarding the SIP profiles, are you talking about on the CME or on the UCM?

[Ayodeji Okanlawon]

Ok..Ken.This is serious..But lets keep going...

Can you send me CUCM traces? Ensure you enable detailed traces in CUCM and send the trace for a failed test call..In the mean time..Please send the ff traces

debug ccsip all

Do another test call and please attach the trace as zip file here..It can be a lot of logs so dont paste just attach.

Once you are done..gather cucm traces and send to me ( i will need to see the ips so I can troubleshoot..If you want to send me a PM and attach the trace then thats fine..

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

[ken.montgomery]

I sent you a private message, please provide me your email address in it, so I can work with you on the problem.  I will review the traces to insure nothing insecure is in there, then post them here if possible, but would prefer to email them to you directly.

[Ayodeji Okanlawon]

Ken,

I have replied. Let me know once you have sent the traces

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

[ken.montgomery]

On the way now.

[Ayodeji Okanlawon]

Ken,

I have looked at the logs and found the correct traces...Questions for you

1. Does the ip address on the sip trunk match the ip address of the CME gateway where you have the bind command

2. Does the CCM group on th sip trunk has the CUCM subscriber in it?

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

[Anas Abueideh]

Hi,

Can you change the dial-peer pointing to CCM to h323 instead of SIP ? when you change you need to add the CME as an H323 Gateway.

voice class h323 2

   h225 timeout tcp establish 3

  h225 timeout setup 3

dial-peer voice 211 voip

description *** INCOMING CALLS FROM FAIRLAWN ****

group-name FairlawnIncoming

destination-pattern 8...

session target ipv4:<---IP Address of CUCM Subscriber Server--->

incoming called-number .

voice-class codec 1

voice-class h323 2

dtmf-relay h245-alphanumeric

!

interface GigabitEthernet0/2

description CONNECTION TO CME-LAN "$ES_LAN$"

ip address <--- IP Address of CME ---> 255.255.255.0

h323 voip interface

h323 voip bind srcipp  <--- IP Address of CME --->

it seems when you use sip, it looks for a SIP endpoint instead of skinny endpoint

HTH

Anas

please rate if it is helpful

[Ayodeji Okanlawon]

Annas,

Why should he do that? Because he has issues with SIP means he should go back to H323...NO thats not right..

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

[Anas Abueideh]

Hi,

do you think H323 is bad ?? if it works at least he has a plan B to figure out this issue.

regards

Anas

[ken.montgomery]

Been there done that.  Actually came to SIP when H323 had same issue.

So whether running on H323 or SIP, calls only flow one way.

[Ayodeji Okanlawon]

Ken,

did you see my  post yesterday.. Can you check the device pool on the sip trunk.. Ensure the CUCM group assigned to it has the subscriber in it

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

[ken.montgomery]

I did not, but I will look.

Ok, I'm not sure how to put the subscriber in a 'device pool'... maybe I'm missing your point. 

The device pool is called Manila_Device_Pool

The SIP trunk has is flagged with Manila_Device_Pool

So how would I put the subscriber into the pool?  I guess I don't understand what you're asking.  Let me look at the original message you sent about it...

1. Does the ip address on the sip trunk match the ip address of the CME gateway where you have the bind command?

          Yes

2. Does the CCM group on th sip trunk has the CUCM subscriber in it?

          Where do you intend for me to put the subscriber into a group... I'm not following your logic on this one.

Thanks, Ken