cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
1722
Views
10
Helpful
15
Replies

Inbound SIP Calls Not Going to VM

CChambleeJr
Level 1
Level 1

Hello all.  I am having trouble getting inbound SIP calls to reach voice mail boxes after call-forward noans.  I have two working CME routers, each as a stand-alone PBX.  I have a SIP trunk configured between them, and can place calls from one CME to the other over the SIP trunk.  I have CUE configured on one of the CMEs, and have mailboxes configured for its three VoIP extensions, 5001, 5002 and 5003.  The VM extension is 2000.  When placing calls from extension 5001 to 5002, the VM picks up the call after three rings, as expected.  But if I place a call from one of the extensions on the other CME over the SIP trunk and dial 5002, extension 5002 will ring three times, then go back idle.  The calling station on the other CME will continue to give ringback until I release the call.  Where should I look for the problem?

15 Replies 15

Dennis Mink
VIP Alumni
VIP Alumni

Its signalling that is broken mate,

run a debug ccsip messages on the system with the phone going to VM, and add the output to the case

Please remember to rate useful posts, by clicking on the stars below.

Same call scenario as above, here's the debug ccsip messages dump:

CME-172-16-1-1#debug ccsip messages
SIP Call messages tracing is enabled
CME-172-16-1-1#
*Feb 24 18:11:20.366: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:5001@10.0.185.70:5060 SIP/2.0
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bK7F24B8
Remote-Party-ID: "SECRET1003" <sip:4003@10.0.185.71>;party=calling;screen=no;privacy=off
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=F29E4F4-150E
To: <sip:5001@10.0.185.70>
Date: Wed, 24 Feb 2016 17:39:59 GMT
Call-ID: 761F612E-DA5411E5-82B7D0DA-8C41CEE@10.0.185.71
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 1965528223-3662942693-2192756954-0147070190
User-Agent: Cisco-SIPGateway/IOS-12.x
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Max-Forwards: 70
Timestamp: 1456335599
Contact: <sip:4003@10.0.185.71:5060;transport=tcp>
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 291

v=0
o=CiscoSystemsSIP-GW-UserAgent 3862 4324 IN IP4 10.0.185.71
s=SIP Call
c=IN IP4 10.0.185.71
t=0 0
m=audio 17102 RTP/AVP 18 101 19
c=IN IP4 10.0.185.71
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:19 CN/8000
a=ptime:20

*Feb 24 18:11:20.374: //221/7527949F82B2/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bK7F24B8
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=F29E4F4-150E
To: <sip:5001@10.0.185.70>
Date: Wed, 24 Feb 2016 18:11:20 GMT
Call-ID: 761F612E-DA5411E5-82B7D0DA-8C41CEE@10.0.185.71
Timestamp: 1456335599
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0


*Feb 24 18:11:20.382: //221/7527949F82B2/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 180 Ringing
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bK7F24B8
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=F29E4F4-150E
To: <sip:5001@10.0.185.70>;tag=F2A8B18-17AC
Date: Wed, 24 Feb 2016 18:11:20 GMT
Call-ID: 761F612E-DA5411E5-82B7D0DA-8C41CEE@10.0.185.71
Timestamp: 1456335599
CSeq: 101 INVITE
Require: 100rel
RSeq: 6597
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Remote-Party-ID: "Chuck" <sip:5001@10.0.185.70>;party=called;screen=no;privacy=off
Contact: <sip:5001@10.0.185.70:5060;transport=tcp>
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0


*Feb 24 18:11:20.386: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
PRACK sip:5001@10.0.185.70:5060;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bK80215C
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=F29E4F4-150E
To: <sip:5001@10.0.185.70>;tag=F2A8B18-17AC
Date: Wed, 24 Feb 2016 17:39:59 GMT
Call-ID: 761F612E-DA5411E5-82B7D0DA-8C41CEE@10.0.185.71
CSeq: 102 PRACK
RAck: 6597 101 INVITE
Allow-Events: telephone-event
Max-Forwards: 70
Content-Length: 0


*Feb 24 18:11:20.390: //221/7527949F82B2/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bK80215C
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=F29E4F4-150E
To: <sip:5001@10.0.185.70>;tag=F2A8B18-17AC
Date: Wed, 24 Feb 2016 18:11:20 GMT
Call-ID: 761F612E-DA5411E5-82B7D0DA-8C41CEE@10.0.185.71
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 102 PRACK
Content-Length: 0


*Feb 24 18:11:32.382: //221/7527949F82B2/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 302 Moved Temporarily
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bK7F24B8
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=F29E4F4-150E
To: <sip:5001@10.0.185.70>;tag=F2A8B18-17AC
Date: Wed, 24 Feb 2016 18:11:20 GMT
Call-ID: 761F612E-DA5411E5-82B7D0DA-8C41CEE@10.0.185.71
Timestamp: 1456335599
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Diversion: <sip:5001@10.0.185.70>;reason=no-answer;counter=1
Contact: <sip:2000@172.16.1.2>
Content-Length: 0


*Feb 24 18:11:32.390: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:5001@10.0.185.70:5060 SIP/2.0
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bK7F24B8
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=F29E4F4-150E
To: <sip:5001@10.0.185.70>;tag=F2A8B18-17AC
Date: Wed, 24 Feb 2016 17:39:59 GMT
Call-ID: 761F612E-DA5411E5-82B7D0DA-8C41CEE@10.0.185.71
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event
Content-Length: 0

configure this under voice service voip

#voice service voip

#allow-connections sip to sip

#no supplementary-service sip moved-temporarily
 #no supplementary-service sip refer

Br, Nadeem Please rate all useful post.

Applied recommended changes.  The symptom has changed now.  Note ccsip messages debug:

*Feb 24 19:18:06.506: //253/C1E8CDC882FA/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bK9E1102
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=F66D72C-1A48
To: <sip:5001@10.0.185.70>;tag=F677D1C-F1E
Date: Wed, 24 Feb 2016 19:17:54 GMT
Call-ID: C2D5039B-DA5D11E5-82FFD0DA-8C41CEE@10.0.185.71
Timestamp: 1456339594
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Reason: Q.850;cause=47
Content-Length: 0


*Feb 24 19:18:06.518: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:5001@10.0.185.70:5060 SIP/2.0
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bK9E1102
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=F66D72C-1A48
To: <sip:5001@10.0.185.70>;tag=F677D1C-F1E
Date: Wed, 24 Feb 2016 18:46:34 GMT
Call-ID: C2D5039B-DA5D11E5-82FFD0DA-8C41CEE@10.0.185.71
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event
Content-Length: 0

Getting "503 Service Unavailable" now.  Comment: My CUE VM module is on a different subnet than the SIP trunk.  The SIP trunk is on the 10.0.185.0 subnet, while the CME and CUE are on 172.16.1.0 subnet, and I have no routes built between those two.  Not even sure if a route is required, but I wanted to mention that.

Yep you need to get the routing fixed.

-Kevin

it really does not matter at all as long CME/Phone IP's able to reach CUE. Are you able the ping the CUE ip address from CME?  you need to check the routes and fix the routing issue.

Can you make just another test and attached current show run and same debug from CME

Br, Nadeem Please rate all useful post.

The phones on CME#2 (where the test calls are originating from), and CME#2 itself are on 172.16.2.0. The target CME (#1) is on 172.16.1.0, and its phones are are on 172.16.100.0.  The SIP trunks are on a different interface, and on 10.0.185.0. Voicemail works fine on CME#1 calling between local extensions. So what routes are needed?

Refreshed CME#1 configuration below. With this configuration, I'm getting the "503 Service Unavailable" message.

CME-172-16-1-1#show run
Building configuration...


Current configuration : 8903 bytes
!
! Last configuration change at 13:18:20 central Wed Feb 24 2016 by Chuck
version 15.1
service timestamps debug datetime msec
service timestamps log datetime msec
no service password-encryption
!
hostname CME-172-16-1-1
!
boot-start-marker
boot-end-marker
!
!
! card type command needed for slot/vwic-slot 0/2
enable password CCJr4471425Enable
!
no aaa new-model
!
clock timezone central -6 0
clock summer-time central recurring
no network-clock-participate slot 1
no network-clock-participate slot 2
--More--  !
dot11 syslog
ip source-route
!
ip cef
!
!
no ip dhcp use vrf connected
!
ip dhcp pool VOICE
network 172.16.100.0 255.255.255.0
default-router 172.16.100.254
option 150 ip 172.16.1.1
!
!
no ip domain lookup
no ipv6 cef
!
multilink bundle-name authenticated
!
!
!
!
!
--More--  voice-card 0
!
voice-card 1
!
voice-card 2
!
!
!
voice service voip
allow-connections sip to sip
no supplementary-service sip moved-temporarily
no supplementary-service sip refer
!
!
!
!
!
crypto pki token default removal timeout 0
!
!
!
!
license udi pid CISCO3825 sn FTX1224A105
username cisco privilege 15 password 0 cisco
--More--  username Chuck privilege 0 password 0 CCJr4471425
!
redundancy
!
!
!
!
!
!
!
!
!
!
interface GigabitEthernet0/0
no ip address
duplex auto
speed auto
media-type sfp
negotiation auto
!
interface GigabitEthernet0/0.1
encapsulation dot1Q 1 native
ip address 172.16.1.1 255.255.255.0
!
--More--  interface GigabitEthernet0/0.100
encapsulation dot1Q 100
ip address 172.16.100.1 255.255.255.0
!
interface GigabitEthernet0/0.101
encapsulation dot1Q 101
ip address 192.168.1.2 255.255.255.0
!
interface Service-Engine0/0
ip unnumbered GigabitEthernet0/0.1
service-module ip address 172.16.1.2 255.255.255.0
service-module ip default-gateway 172.16.1.1
!
interface GigabitEthernet0/1
description SIP trunk to CME-2
ip address 10.0.185.70 255.255.255.0
duplex full
speed 100
media-type rj45
!
ip forward-protocol nd
ip http server
ip http authentication local
no ip http secure-server
--More--  
CME-172-16-1-1#
CME-172-16-1-1#show run
Building configuration...


Current configuration : 8903 bytes
!
! Last configuration change at 13:18:20 central Wed Feb 24 2016 by Chuck
version 15.1
service timestamps debug datetime msec
service timestamps log datetime msec
no service password-encryption
!
hostname CME-172-16-1-1
!
boot-start-marker
boot-end-marker
!
!
! card type command needed for slot/vwic-slot 0/2
enable password CCJr4471425Enable
!
no aaa new-model
!
clock timezone central -6 0
clock summer-time central recurring
no network-clock-participate slot 1
no network-clock-participate slot 2
--More--  !
dot11 syslog
ip source-route
!
ip cef
!
!
no ip dhcp use vrf connected
!
ip dhcp pool VOICE
network 172.16.100.0 255.255.255.0
default-router 172.16.100.254
option 150 ip 172.16.1.1
!
!
no ip domain lookup
no ipv6 cef
!
multilink bundle-name authenticated
!
!
!
!
!
--More--  voice-card 0
!
voice-card 1
!
voice-card 2
!
!
!
voice service voip
allow-connections sip to sip
no supplementary-service sip moved-temporarily
no supplementary-service sip refer
!
!
!
!
!
crypto pki token default removal timeout 0
!
!
!
!
license udi pid CISCO3825 sn FTX1224A105
username cisco privilege 15 password 0 cisco
--More--  username Chuck privilege 0 password 0 CCJr4471425
!
redundancy
!
!
!
!
!
!
!
!
!
!
interface GigabitEthernet0/0
no ip address
duplex auto
speed auto
media-type sfp
negotiation auto
!
interface GigabitEthernet0/0.1
encapsulation dot1Q 1 native
ip address 172.16.1.1 255.255.255.0
!
--More--  interface GigabitEthernet0/0.100
encapsulation dot1Q 100
ip address 172.16.100.1 255.255.255.0
!
interface GigabitEthernet0/0.101
encapsulation dot1Q 101
ip address 192.168.1.2 255.255.255.0
!
interface Service-Engine0/0
ip unnumbered GigabitEthernet0/0.1
service-module ip address 172.16.1.2 255.255.255.0
service-module ip default-gateway 172.16.1.1
!
interface GigabitEthernet0/1
description SIP trunk to CME-2
ip address 10.0.185.70 255.255.255.0
duplex full
speed 100
media-type rj45
!
ip forward-protocol nd
ip http server
ip http authentication local
no ip http secure-server
--More--  ip http path flash:/GUI
!
!
ip route 172.16.1.2 255.255.255.255 Service-Engine0/0
ip route 172.16.2.0 255.255.255.0 172.16.1.254
!
!
!
!
!
!
tftp-server flash:term06.default.loads
tftp-server flash:term41.default.loads
tftp-server flash:term42.default.loads
tftp-server flash:term62.default.loads
tftp-server flash:term45.default.loads
tftp-server flash:term65.default.loads
tftp-server flash:term70.default.loads
tftp-server flash:term71.default.loads
tftp-server flash:Desktops/320x212x12/CampusNight.png
tftp-server flash:Desktops/320x212x12/CiscoFountain.png
tftp-server flash:Desktops/320x212x12/MorroRock.png
tftp-server flash:Desktops/320x212x12/NantucketFlowers.png
tftp-server flash:Desktops/320x212x12/TN-CampusNight.png
--More--  tftp-server flash:Desktops/320x212x12/TN-CiscoFountain.png
tftp-server flash:Desktops/320x212x12/TN-Fountain.png
tftp-server flash:Desktops/320x212x12/TN-MorroRock.png
tftp-server flash:Desktops/320x212x12/TN-NantucketFlowers.png
tftp-server flash:Desktops/320x212x12/Fountain.png
tftp-server flash:Desktops/320x212x12/CiscoLogo.png
tftp-server flash:Desktops/320x212x12/TN-CiscoLogo.png
tftp-server flash:Desktops/320x212x12/List.xml
tftp-server flash:Desktops/320x216x16/List.xml
tftp-server flash:Desktops/320x212x16/List.xml
tftp-server flash:term61.default.loads
tftp-server flash:term75.default.loads
tftp-server flash:P00307020400.bin
tftp-server flash:P00307020400.loads
tftp-server flash:P00307020400.sb2
tftp-server flash:P00307020400.sbn
tftp-server flash:P0030801SR02.sbn
tftp-server flash:P0030801SR02.loads
tftp-server flash:P0030801SR02.sb2
tftp-server flash:P0030801SR02.bin
tftp-server flash:P00308010200.sbn
tftp-server flash:P00308010200.loads
tftp-server flash:P00308010200.sb2
tftp-server flash:P00308010200.bin
--More--  tftp-server flash:P00308000400.bin
tftp-server flash:P00308000400.loads
tftp-server flash:P00308000400.sb2
tftp-server flash:P00308000400.sbn
tftp-server flash:term31.default.loads
tftp-server flash:SCCP31.9-4-2SR1-1S.loads
tftp-server flash:jar31sccp.9-4-2ES9.sbn
tftp-server flash:dsp31.9-4-2ES9.sbn
tftp-server flash:cvm31sccp.9-4-2ES9.sbn
tftp-server flash:cnu31.9-4-2ES9.sbn
tftp-server flash:apps31.9-4-2ES9.sbn
!
control-plane
!
!
voice-port 1/0/0
connection plar 5001
caller-id enable
!
voice-port 1/0/1
connection plar 5002
caller-id enable
!
voice-port 1/0/2
--More--   connection plar 5003
caller-id enable
!
voice-port 1/0/3
!
voice-port 2/0/0
ring cadence pattern01
station-id name Charles
station-id number 5011
caller-id enable
!
voice-port 2/0/1
!
!
!
mgcp profile default
!
!
dial-peer voice 1 voip
destination-pattern 2...
session protocol sipv2
session target ipv4:172.16.1.2
dtmf-relay sip-notify
codec g711ulaw
--More--   no vad
!
dial-peer voice 11 pots
destination-pattern 9[2-9].........
port 1/0/3
prefix 99,
!
dial-peer voice 21 pots
destination-pattern 5011
port 2/0/0
!
dial-peer voice 31 voip
description Outbound SIP to CME-2 - Local
destination-pattern 4...
session protocol sipv2
session target ipv4:10.0.185.71
session transport tcp
dtmf-relay rtp-nte
!
dial-peer voice 32 voip
description Incoming from CME-2
destination-pattern 5...
session protocol sipv2
session target ipv4:10.0.185.71
--More--   session transport tcp
dtmf-relay rtp-nte
!
dial-peer voice 33 voip
description Outbound SIP to Avaya Lab
destination-pattern 300....
session protocol sipv2
session target ipv4:10.0.185.235
session transport tcp
dtmf-relay rtp-nte
!
dial-peer voice 34 voip
description Incoming SIP from Avaya
destination-pattern 5...
session protocol sipv2
session target ipv4:10.0.185.235
session transport tcp
dtmf-relay rtp-nte
!
!
!
!
telephony-service
max-ephones 30
--More--   max-dn 45
ip source-address 172.16.1.1 port 2000
auto assign 1 to 10 type 7912
auto assign 1 to 10 type 7941
auto assign 1 to 10 type 7940
auto assign 1 to 10 type 7960
auto assign 1 to 10 type 7961
auto assign 1 to 10 type 7965
auto assign 1 to 10 type 7945
auto assign 1 to 10 type 7942
auto assign 1 to 10 type 7962
auto assign 1 to 10 type 7970
auto assign 1 to 10 type 7971
auto assign 1 to 10 type 7975
system message B5298 Voice Lab 1
cnf-file location flash:
load 7912 term06.default.loads
load 7960-7940 P00308000400
load 7941 term41.default.loads
load 7942 term42.default.loads
load 7945 term45.default.loads
load 7961 term61.default.loads
load 7962 term62.default.loads
load 7965 term65.default.loads
--More--   load 7970 term70.default.loads
load 7971 term71.default.loads
load 7975 term75.default.loads
time-zone 8
voicemail 2000
max-conferences 4 gain -6
web admin system name cisco password cisco
dn-webedit
time-webedit
transfer-system full-consult
secondary-dialtone 9
create cnf-files version-stamp Jan 01 2002 00:00:00
!
!
ephone-dn 1 dual-line
number 5001
label Chuck
name Chuck
preference 1 secondary 2
call-forward busy 2000
call-forward noan 2000 timeout 12
!
!
ephone-dn 2 dual-line
--More--   number 5002
label Greg
name Greg
call-forward busy 2000
call-forward noan 2000 timeout 12
!
!
ephone-dn 3 dual-line
number 5003
label Sam
name Sam
call-forward busy 2000
call-forward noan 2000 timeout 12
!
!
ephone-dn 4 dual-line
number 1004
call-forward busy 2000
call-forward noan 2000 timeout 12
!
!
ephone-dn 5 dual-line
number 1005
call-forward busy 2000
--More--   call-forward noan 2000 timeout 12
!
!
ephone-dn 6 dual-line
number 1006
call-forward busy 2000
call-forward noan 2000 timeout 12
!
!
ephone-dn 7 dual-line
number 1007
call-forward busy 2000
call-forward noan 2000 timeout 12
!
!
ephone-dn 8 dual-line
number 1008
call-forward busy 2000
call-forward noan 2000 timeout 12
!
!
ephone-dn 9 dual-line
number 1009
call-forward busy 2000
--More--   call-forward noan 2000 timeout 12
!
!
ephone-dn 10 dual-line
number 1010
call-forward busy 2000
call-forward noan 2000 timeout 12
!
!
ephone-dn 21
number 8000....
mwi on
!
!
ephone-dn 22
number 8001....
mwi off
!
!
ephone 1
device-security-mode none
mac-address 0012.0138.3FD2
type 7960
button 1:2
--More--  !
!
!
ephone 2
device-security-mode none
mac-address 0016.C815.61DD
type 7960
button 1:1
!
!
!
ephone 3
device-security-mode none
mac-address 0016.468A.DD37
type 7960
button 1:3
!
!
!
ephone 4
device-security-mode none
mac-address 001B.D423.FB79
max-calls-per-button 2
type 7931
--More--   button 1:4 2:1 3:2 4:3
!
!
!
ephone 5
device-security-mode none
mac-address 0017.5A5B.2A74
type 7960
button 1:5
!
!
!
ephone 6
device-security-mode none
mac-address 000C.8533.CD16
type 7960
button 1:6
!
!
!
!
line con 0
line aux 0
line 194
--More--   no activation-character
no exec
transport preferred none
transport input all
transport output lat pad telnet rlogin lapb-ta mop udptn v120 ssh
line vty 0 4
exec-timeout 60 0
login local
transport input all
line vty 5 15
exec-timeout 60 0
login
transport input all
!
scheduler allocate 20000 1000
ntp server 172.16.1.4
ntp server 172.16.1.9
end

CME-172-16-1-1#

And here's the debugs:

ccsip messages:

*Feb 24 20:43:09.165: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:5001@10.0.185.70:5060 SIP/2.0
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bKA2967
Remote-Party-ID: "SECRET1003" <sip:4003@10.0.185.71>;party=calling;screen=no;privacy=off
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=FB4E2A8-31A
To: <sip:5001@10.0.185.70>
Date: Wed, 24 Feb 2016 20:11:48 GMT
Call-ID: AB75902E-DA6911E5-830BD0DA-8C41CEE@10.0.185.71
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 2862368665-3664318949-2198261978-0147070190
User-Agent: Cisco-SIPGateway/IOS-12.x
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Max-Forwards: 70
Timestamp: 1456344708
Contact: <sip:4003@10.0.185.71:5060;transport=tcp>
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 291

v=0
o=CiscoSystemsSIP-GW-UserAgent 2425 1417 IN IP4 10.0.185.71
s=SIP Call
c=IN IP4 10.0.185.71
t=0 0
m=audio 18768 RTP/AVP 18 101 19
c=IN IP4 10.0.185.71
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:19 CN/8000
a=ptime:20

*Feb 24 20:43:09.173: //259/AA9C47998306/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bKA2967
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=FB4E2A8-31A
To: <sip:5001@10.0.185.70>
Date: Wed, 24 Feb 2016 20:43:09 GMT
Call-ID: AB75902E-DA6911E5-830BD0DA-8C41CEE@10.0.185.71
Timestamp: 1456344708
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0


*Feb 24 20:43:09.181: //259/AA9C47998306/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 180 Ringing
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bKA2967
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=FB4E2A8-31A
To: <sip:5001@10.0.185.70>;tag=FB58858-1081
Date: Wed, 24 Feb 2016 20:43:09 GMT
Call-ID: AB75902E-DA6911E5-830BD0DA-8C41CEE@10.0.185.71
Timestamp: 1456344708
CSeq: 101 INVITE
Require: 100rel
RSeq: 5076
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Remote-Party-ID: "Chuck" <sip:5001@10.0.185.70>;party=called;screen=no;privacy=off
Contact: <sip:5001@10.0.185.70:5060;transport=tcp>
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0


*Feb 24 20:43:09.185: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
PRACK sip:5001@10.0.185.70:5060;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bKA38AD
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=FB4E2A8-31A
To: <sip:5001@10.0.185.70>;tag=FB58858-1081
Date: Wed, 24 Feb 2016 20:11:48 GMT
Call-ID: AB75902E-DA6911E5-830BD0DA-8C41CEE@10.0.185.71
CSeq: 102 PRACK
RAck: 5076 101 INVITE
Allow-Events: telephone-event
Max-Forwards: 70
Content-Length: 0


*Feb 24 20:43:09.189: //259/AA9C47998306/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bKA38AD
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=FB4E2A8-31A
To: <sip:5001@10.0.185.70>;tag=FB58858-1081
Date: Wed, 24 Feb 2016 20:43:09 GMT
Call-ID: AB75902E-DA6911E5-830BD0DA-8C41CEE@10.0.185.71
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 102 PRACK
Content-Length: 0


*Feb 24 20:43:21.185: //259/AA9C47998306/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bKA2967
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=FB4E2A8-31A
To: <sip:5001@10.0.185.70>;tag=FB58858-1081
Date: Wed, 24 Feb 2016 20:43:09 GMT
Call-ID: AB75902E-DA6911E5-830BD0DA-8C41CEE@10.0.185.71
Timestamp: 1456344708
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Reason: Q.850;cause=47
Content-Length: 0


*Feb 24 20:43:21.197: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:5001@10.0.185.70:5060 SIP/2.0
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bKA2967
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=FB4E2A8-31A
To: <sip:5001@10.0.185.70>;tag=FB58858-1081
Date: Wed, 24 Feb 2016 20:11:48 GMT
Call-ID: AB75902E-DA6911E5-830BD0DA-8C41CEE@10.0.185.71
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event
Content-Length: 0

And here's the ccapi inout debug:

CME-172-16-1-1#debug voice ccapi inout  
voip ccapi inout debugging is on
CME-172-16-1-1#
*Feb 24 20:47:36.517: //-1/495E5D7C830C/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=4003
----- ccCallInfo IE subfields -----
cisco-ani=4003
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=5001
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

*Feb 24 20:47:36.517: //-1/495E5D7C830C/CCAPI/cc_api_call_setup_ind_common:
Interface=0x69D1B604, Call Info(
Calling Number=4003,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=5001(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
Incoming Dial-peer=31, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=262
*Feb 24 20:47:36.517: //-1/495E5D7C830C/CCAPI/ccCheckClipClir:
In: Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 20:47:36.517: //-1/495E5D7C830C/CCAPI/ccCheckClipClir:
Out: Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 20:47:36.517: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:36.517: :cc_get_feature_vsa malloc success
*Feb 24 20:47:36.517: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:36.517: cc_get_feature_vsa count is 1
*Feb 24 20:47:36.517: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:36.517: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763335232,feature_id:442
*Feb 24 20:47:36.517: //262/495E5D7C830C/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=5001(TON=Unknown, NPI=Unknown))
*Feb 24 20:47:36.517: //262/495E5D7C830C/CCAPI/cc_process_call_setup_ind:
Event=0x6A46BE00
*Feb 24 20:47:36.517: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
Try with the demoted called number 5001
*Feb 24 20:47:36.521: //262/495E5D7C830C/CCAPI/ccCallSetContext:
Context=0x6CC0DDEC
*Feb 24 20:47:36.521: //262/495E5D7C830C/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 262 with tag 31 to app "_ManagedAppProcess_Default"
*Feb 24 20:47:36.521: //262/495E5D7C830C/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
*Feb 24 20:47:36.521: //262/495E5D7C830C/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=20001, Params=0x6CBFF9FC, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
*Feb 24 20:47:36.521: //262/495E5D7C830C/CCAPI/ccCheckClipClir:
In: Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 20:47:36.521: //262/495E5D7C830C/CCAPI/ccCheckClipClir:
Out: Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 20:47:36.521: //262/495E5D7C830C/CCAPI/ccCallSetupRequest:
Destination Pattern=5001$, Called Number=5001, Digit Strip=TRUE
*Feb 24 20:47:36.521: //262/495E5D7C830C/CCAPI/ccCallSetupRequest:
Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=5001(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=SECRET1003
Account Number=4003, Final Destination Flag=TRUE,
Guid=495E5D7C-DA6A-11E5-830C-D0DA08C41CEE, Outgoing Dial-peer=20001
*Feb 24 20:47:36.521: //262/495E5D7C830C/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=4003
----- ccCallInfo IE subfields -----
cisco-ani=4003
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=5001
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

*Feb 24 20:47:36.521: //262/495E5D7C830C/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x7222B574, Interface Type=6, Destination=, Mode=0x0,
Call Params(Calling Number=4003,(Calling Name=SECRET1003)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=5001(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=20001, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
*Feb 24 20:47:36.525: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:36.525: :cc_get_feature_vsa malloc success
*Feb 24 20:47:36.525: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:36.525: cc_get_feature_vsa count is 2
*Feb 24 20:47:36.525: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:36.525: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763335008,feature_id:443
*Feb 24 20:47:36.525: //263/495E5D7C830C/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1
*Feb 24 20:47:36.525: //263/495E5D7C830C/CCAPI/ccCallSetContext:
Context=0x6CBFF9AC
*Feb 24 20:47:36.525: //262/495E5D7C830C/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=20001
*Feb 24 20:47:36.525: //263/495E5D7C830C/CCAPI/cc_api_update_call_info:
Interface=0x7222B574, Call Id=0x107
*Feb 24 20:47:36.525: //263/495E5D7C830C/CCAPI/cc_api_call_proceeding:
Interface=0x7222B574, Progress Indication=NULL(0)
*Feb 24 20:47:36.529: //263/495E5D7C830C/CCAPI/cc_api_call_alert:
Interface=0x7222B574, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
*Feb 24 20:47:36.529: //263/495E5D7C830C/CCAPI/cc_api_call_alert:
Call Entry(Retry Count=0, Responsed=TRUE)
*Feb 24 20:47:36.529: //262/495E5D7C830C/CCAPI/ccCallAlert:
Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
*Feb 24 20:47:36.529: //262/495E5D7C830C/CCAPI/ccCallAlert:
Call Entry(Responsed=TRUE, Alert Sent=TRUE)
*Feb 24 20:47:36.529: //263/495E5D7C830C/CCAPI/ccCallFeature:
Feature Type=25, Call Id=263
*Feb 24 20:47:36.529: //262/495E5D7C830C/CCAPI/ccCallNotify:
Data Bitmask=0x7, Call Id=262
*Feb 24 20:47:48.529: //263/495E5D7C830C/CCAPI/cc_api_call_disconnected:
Cause Value=19, Interface=0x7222B574, Call Id=263
*Feb 24 20:47:48.529: //263/495E5D7C830C/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=19, Retry Count=0)
*Feb 24 20:47:48.529: //262/495E5D7C830C/CCAPI/ccCallReleaseResources:
release reserved xcoding resource.
*Feb 24 20:47:48.529: //263/495E5D7C830C/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/ccUpdateRedirectingNumber:
type=6 redirecting_number=5001
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/ccUpdateRedirectNumber:
type=6 Original Called Number=5001, Called Number=5001, Calling Number=4003, Calling DN=-1 Calling Id=262,
Redirect Number=2000, Redirect Reason=2
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/ccUpdateRedirectingNumber:
type=6 redirecting_number=5001
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.529: :cc_get_feature_vsa malloc success
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.529: cc_get_feature_vsa count is 3
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.529: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763335456,feature_id:444
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 20:47:48.529: feature_vsa is 691A5C38,featname is 0
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.529: :cc_get_feature_vsa malloc success
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.529: cc_get_feature_vsa count is 4
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.529: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763334784,feature_id:445
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 20:47:48.529: : Generating new featurevsa,inserting it
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 20:47:48.529: feature call forward featname is 3
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 20:47:48.529: feature_vsa is 691A5B58,featname is 0
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.529: :cc_get_feature_vsa malloc success
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.529: cc_get_feature_vsa count is 5
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.529: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763335680,feature_id:446
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 20:47:48.529: : Generating new featurevsa,inserting it
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 20:47:48.529: feature call forward featname is 3
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 20:47:48.529: :cc_free_feature_vsa freeing 691A5D18
*Feb 24 20:47:48.529: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 20:47:48.529: vsacount in free is 4
*Feb 24 20:47:48.529: //263/495E5D7C830C/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=19)
*Feb 24 20:47:48.529: //263/495E5D7C830C/CCAPI/ccCallDisconnect:
Cause Value=19, Call Entry(Responsed=TRUE, Cause Value=19)
*Feb 24 20:47:48.529: //263/495E5D7C830C/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
*Feb 24 20:47:48.533: //263/495E5D7C830C/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x7222B574, Tag=0x0, Call Id=263,
Call Entry(Disconnect Cause=19, Voice Class Cause Code=0, Retry Count=0)
*Feb 24 20:47:48.533: //263/495E5D7C830C/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Feb 24 20:47:48.533: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 20:47:48.533: :cc_free_feature_vsa freeing 691A5DF8
*Feb 24 20:47:48.533: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 20:47:48.533: vsacount in free is 3
*Feb 24 20:47:48.533: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 20:47:48.533: vsacount in free is 2
*Feb 24 20:47:48.533: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.533: :cc_get_feature_vsa malloc success
*Feb 24 20:47:48.533: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.533: cc_get_feature_vsa count is 3
*Feb 24 20:47:48.533: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.533: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763335008,feature_id:447
*Feb 24 20:47:48.533: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 20:47:48.537: feature call forward featname is 3
*Feb 24 20:47:48.537: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 20:47:48.537: :cc_free_feature_vsa freeing 691A5B58
*Feb 24 20:47:48.537: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 20:47:48.537: vsacount in free is 2
*Feb 24 20:47:48.537: //262/495E5D7C830C/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=1, Params=0x6CC145FC, Progress Indication=NULL(0)
*Feb 24 20:47:48.537: //262/495E5D7C830C/CCAPI/ccCheckClipClir:
In: Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 20:47:48.537: //262/495E5D7C830C/CCAPI/ccCheckClipClir:
Out: Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 20:47:48.537: //262/495E5D7C830C/CCAPI/ccCallSetupRequest:
Destination Pattern=2..., Called Number=2000, Digit Strip=FALSE
*Feb 24 20:47:48.537: //262/495E5D7C830C/CCAPI/ccCallSetupRequest:
Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=2000(TON=Unknown, NPI=Unknown),
Redirect Number=5001, Display Info=SECRET1003
Account Number=4003, Final Destination Flag=TRUE,
Guid=B2C8012A-DA6E-11E5-82E9-D52F405667DF, Outgoing Dial-peer=1
*Feb 24 20:47:48.537: //262/495E5D7C830C/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=4003
----- ccCallInfo IE subfields -----
cisco-ani=4003
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=2000
cisco-desttype=0
cisco-destplan=0
cisco-rdie=73
cisco-rdn=5001
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=2 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

*Feb 24 20:47:48.537: //262/495E5D7C830C/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x69D1B604, Interface Type=3, Destination=, Mode=0x0,
Call Params(Calling Number=4003,(Calling Name=SECRET1003)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=2000(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=1, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
*Feb 24 20:47:48.537: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.537: :cc_get_feature_vsa malloc success
*Feb 24 20:47:48.537: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.537: cc_get_feature_vsa count is 3
*Feb 24 20:47:48.537: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.537: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763335008,feature_id:448
*Feb 24 20:47:48.537: //264/495E5D7C830C/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1
*Feb 24 20:47:48.537: //264/495E5D7C830C/CCAPI/ccCallSetContext:
Context=0x6CC145AC
*Feb 24 20:47:48.537: //262/495E5D7C830C/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=1
*Feb 24 20:47:48.537: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 20:47:48.537: feature call forward featname is 3
*Feb 24 20:47:48.537: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 20:47:48.537: feature_vsa is 691A5B58,featname is 0
*Feb 24 20:47:48.537: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.537: :cc_get_feature_vsa malloc success
*Feb 24 20:47:48.537: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.537: cc_get_feature_vsa count is 4
*Feb 24 20:47:48.537: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 20:47:48.537: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763335680,feature_id:449
*Feb 24 20:47:48.537: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 20:47:48.537: : Generating new featurevsa,inserting it
*Feb 24 20:47:48.537: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 20:47:48.537: feature call forward featname is 3
*Feb 24 20:47:48.541: //264/495E5D7C830C/CCAPI/cc_api_call_disconnected:
Cause Value=47, Interface=0x69D1B604, Call Id=264
*Feb 24 20:47:48.541: //264/495E5D7C830C/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=47, Retry Count=0)
*Feb 24 20:47:48.541: //264/495E5D7C830C/CCAPI/cc_api_call_disconnected:
Cause Value=47, Interface=0x69D1B604, Call Id=264
*Feb 24 20:47:48.541: //264/495E5D7C830C/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=47, Retry Count=0)
*Feb 24 20:47:48.541: //262/495E5D7C830C/CCAPI/ccCallReleaseResources:
release reserved xcoding resource.
*Feb 24 20:47:48.541: //264/495E5D7C830C/CCAPI/ccCallSetAAA_Accounting:
Accounting=0, Call Id=264
*Feb 24 20:47:48.541: //264/495E5D7C830C/CCAPI/ccCallDisconnect:
Cause Value=47, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=47)
*Feb 24 20:47:48.541: //264/495E5D7C830C/CCAPI/ccCallDisconnect:
Cause Value=47, Call Entry(Responsed=TRUE, Cause Value=47)
*Feb 24 20:47:48.541: //264/495E5D7C830C/CCAPI/cc_api_call_disconnect_done:
Disposition=-11, Interface=0x69D1B604, Tag=0x0, Call Id=264,
Call Entry(Disconnect Cause=47, Voice Class Cause Code=0, Retry Count=0)
*Feb 24 20:47:48.541: //264/495E5D7C830C/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Feb 24 20:47:48.541: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 20:47:48.541: :cc_free_feature_vsa freeing 691A5DF8
*Feb 24 20:47:48.541: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 20:47:48.541: vsacount in free is 3
*Feb 24 20:47:48.541: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 20:47:48.541: vsacount in free is 2
*Feb 24 20:47:48.541: //262/495E5D7C830C/CCAPI/ccCallDisconnect:
Cause Value=47, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
*Feb 24 20:47:48.541: //262/495E5D7C830C/CCAPI/ccCallDisconnect:
Cause Value=47, Call Entry(Responsed=TRUE, Cause Value=47)
*Feb 24 20:47:48.557: //262/495E5D7C830C/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x69D1B604, Tag=0x0, Call Id=262,
Call Entry(Disconnect Cause=47, Voice Class Cause Code=0, Retry Count=0)
*Feb 24 20:47:48.557: //262/495E5D7C830C/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Feb 24 20:47:48.557: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 20:47:48.557: :cc_free_feature_vsa freeing 691A5A78
*Feb 24 20:47:48.557: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 20:47:48.557: vsacount in free is 1
*Feb 24 20:47:48.557: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 20:47:48.557: vsacount in free is 0

******************

In trying to think this thing through, I can't see where any IP routes are lacking, because the two CMEs are signalling each other over the 10.0.185.0 network (SIP trunk). I can call from phones on CME#1 to phones on CME#2, and have talk paths. It's just the hand-off to ext 2000 (CUE) that's breaking down. If I temporarily change the call-forward noan to point to another local extension on CME#1 rather than the VM extension and redo the test call, the call forwards properly to the target extension and I can complete the call.

dial-peer voice 31 voip
description Outbound SIP to CME-2 - Local
destination-pattern 4...
session protocol sipv2
session target ipv4:10.0.185.71
no session transport tcp======> remove this
dtmf-relay rtp-nte

enable the below debugs at the same time and make test call please do take separate debug logs

debug voice ccapi inout

debug ccsip message

alsp please check your IM .

Br,
nadeem

Br, Nadeem Please rate all useful post.

Made following changes:

dial-peer voice 31 voip
description Outbound SIP to CME-2 - Local
destination-pattern 4...
session protocol sipv2
session target ipv4:10.0.185.71
dtmf-relay rtp-nte
!
dial-peer voice 32 voip
description Incoming from CME-2
destination-pattern 5...
session protocol sipv2
session target ipv4:10.0.185.71
dtmf-relay rtp-nte

Here's the two debugs for the test call. No change in symptoms.

*Feb 24 22:05:21.641: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:5001@10.0.185.70:5060 SIP/2.0
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bKB221A8
Remote-Party-ID: "SECRET1003" <sip:4003@10.0.185.71>;party=calling;screen=no;privacy=off
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=10002668-497
To: <sip:5001@10.0.185.70>
Date: Wed, 24 Feb 2016 21:34:01 GMT
Call-ID: 277BFFA4-DA7511E5-8335D0DA-8C41CEE@10.0.185.71
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 0641357834-3665105381-2201014490-0147070190
User-Agent: Cisco-SIPGateway/IOS-12.x
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Max-Forwards: 70
Timestamp: 1456349641
Contact: <sip:4003@10.0.185.71:5060;transport=tcp>
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 291

v=0
o=CiscoSystemsSIP-GW-UserAgent 3459 2351 IN IP4 10.0.185.71
s=SIP Call
c=IN IP4 10.0.185.71
t=0 0
m=audio 19490 RTP/AVP 18 101 19
c=IN IP4 10.0.185.71
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:19 CN/8000
a=ptime:20

*Feb 24 22:05:21.649: //-1/263A580A8330/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=4003
----- ccCallInfo IE subfields -----
cisco-ani=4003
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=5001
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

*Feb 24 22:05:21.649: //-1/263A580A8330/CCAPI/cc_api_call_setup_ind_common:
Interface=0x69D1B604, Call Info(
Calling Number=4003,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=5001(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
Incoming Dial-peer=31, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=280
*Feb 24 22:05:21.649: //-1/263A580A8330/CCAPI/ccCheckClipClir:
In: Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 22:05:21.649: //-1/263A580A8330/CCAPI/ccCheckClipClir:
Out: Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 22:05:21.649: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:21.649: :cc_get_feature_vsa malloc success
*Feb 24 22:05:21.649: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:21.649: cc_get_feature_vsa count is 1
*Feb 24 22:05:21.649: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:21.649: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763335232,feature_id:490
*Feb 24 22:05:21.649: //280/263A580A8330/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=5001(TON=Unknown, NPI=Unknown))
*Feb 24 22:05:21.649: //280/263A580A8330/CCAPI/cc_process_call_setup_ind:
Event=0x6A46BE00
*Feb 24 22:05:21.649: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
Try with the demoted called number 5001
*Feb 24 22:05:21.649: //280/263A580A8330/CCAPI/ccCallSetContext:
Context=0x6CC11C2C
*Feb 24 22:05:21.653: //280/263A580A8330/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 280 with tag 31 to app "_ManagedAppProcess_Default"
*Feb 24 22:05:21.653: //280/263A580A8330/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bKB221A8
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=10002668-497
To: <sip:5001@10.0.185.70>
Date: Wed, 24 Feb 2016 22:05:21 GMT
Call-ID: 277BFFA4-DA7511E5-8335D0DA-8C41CEE@10.0.185.71
Timestamp: 1456349641
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0

*Feb 24 22:05:21.653: //280/263A580A8330/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
*Feb 24 22:05:21.653: //280/263A580A8330/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=20001, Params=0x6CC0B4BC, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
*Feb 24 22:05:21.653: //280/263A580A8330/CCAPI/ccCheckClipClir:
In: Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 22:05:21.653: //280/263A580A8330/CCAPI/ccCheckClipClir:
Out: Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 22:05:21.653: //280/263A580A8330/CCAPI/ccCallSetupRequest:
Destination Pattern=5001$, Called Number=5001, Digit Strip=TRUE
*Feb 24 22:05:21.653: //280/263A580A8330/CCAPI/ccCallSetupRequest:
Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=5001(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=SECRET1003
Account Number=4003, Final Destination Flag=TRUE,
Guid=263A580A-DA75-11E5-8330-D0DA08C41CEE, Outgoing Dial-peer=20001
*Feb 24 22:05:21.653: //280/263A580A8330/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=4003
----- ccCallInfo IE subfields -----
cisco-ani=4003
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=5001
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

*Feb 24 22:05:21.653: //280/263A580A8330/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x7222B574, Interface Type=6, Destination=, Mode=0x0,
Call Params(Calling Number=4003,(Calling Name=SECRET1003)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=5001(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=20001, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
*Feb 24 22:05:21.653: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:21.653: :cc_get_feature_vsa malloc success
*Feb 24 22:05:21.653: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:21.653: cc_get_feature_vsa count is 2
*Feb 24 22:05:21.653: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:21.653: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763335680,feature_id:491
*Feb 24 22:05:21.657: //281/263A580A8330/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1
*Feb 24 22:05:21.657: //281/263A580A8330/CCAPI/ccCallSetContext:
Context=0x6CC0B46C
*Feb 24 22:05:21.657: //280/263A580A8330/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=20001
*Feb 24 22:05:21.657: //281/263A580A8330/CCAPI/cc_api_update_call_info:
Interface=0x7222B574, Call Id=0x119
*Feb 24 22:05:21.657: //281/263A580A8330/CCAPI/cc_api_call_proceeding:
Interface=0x7222B574, Progress Indication=NULL(0)
*Feb 24 22:05:21.661: //281/263A580A8330/CCAPI/cc_api_call_alert:
Interface=0x7222B574, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
*Feb 24 22:05:21.661: //281/263A580A8330/CCAPI/cc_api_call_alert:
Call Entry(Retry Count=0, Responsed=TRUE)
*Feb 24 22:05:21.661: //280/263A580A8330/CCAPI/ccCallAlert:
Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
*Feb 24 22:05:21.661: //280/263A580A8330/CCAPI/ccCallAlert:
Call Entry(Responsed=TRUE, Alert Sent=TRUE)
*Feb 24 22:05:21.661: //281/263A580A8330/CCAPI/ccCallFeature:
Feature Type=25, Call Id=281
*Feb 24 22:05:21.661: //280/263A580A8330/CCAPI/ccCallNotify:
Data Bitmask=0x7, Call Id=280
*Feb 24 22:05:21.661: //280/263A580A8330/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 180 Ringing
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bKB221A8
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=10002668-497
To: <sip:5001@10.0.185.70>;tag=1000CBD8-17FF
Date: Wed, 24 Feb 2016 22:05:21 GMT
Call-ID: 277BFFA4-DA7511E5-8335D0DA-8C41CEE@10.0.185.71
Timestamp: 1456349641
CSeq: 101 INVITE
Require: 100rel
RSeq: 6658
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Remote-Party-ID: "Chuck" <sip:5001@10.0.185.70>;party=called;screen=no;privacy=off
Contact: <sip:5001@10.0.185.70:5060;transport=tcp>
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0

*Feb 24 22:05:21.669: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
PRACK sip:5001@10.0.185.70:5060;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bKB323C7
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=10002668-497
To: <sip:5001@10.0.185.70>;tag=1000CBD8-17FF
Date: Wed, 24 Feb 2016 21:34:01 GMT
Call-ID: 277BFFA4-DA7511E5-8335D0DA-8C41CEE@10.0.185.71
CSeq: 102 PRACK
RAck: 6658 101 INVITE
Allow-Events: telephone-event
Max-Forwards: 70
Content-Length: 0

*Feb 24 22:05:21.669: //280/263A580A8330/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bKB323C7
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=10002668-497
To: <sip:5001@10.0.185.70>;tag=1000CBD8-17FF
Date: Wed, 24 Feb 2016 22:05:21 GMT
Call-ID: 277BFFA4-DA7511E5-8335D0DA-8C41CEE@10.0.185.71
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 102 PRACK
Content-Length: 0

*Feb 24 22:05:33.661: //281/263A580A8330/CCAPI/cc_api_call_disconnected:
Cause Value=19, Interface=0x7222B574, Call Id=281
*Feb 24 22:05:33.661: //281/263A580A8330/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=19, Retry Count=0)
*Feb 24 22:05:33.661: //280/263A580A8330/CCAPI/ccCallReleaseResources:
release reserved xcoding resource.
*Feb 24 22:05:33.661: //281/263A580A8330/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/ccUpdateRedirectingNumber:
type=6 redirecting_number=5001
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/ccUpdateRedirectNumber:
type=6 Original Called Number=5001, Called Number=5001, Calling Number=4003, Calling DN=-1 Calling Id=280,
Redirect Number=2000, Redirect Reason=2
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/ccUpdateRedirectingNumber:
type=6 redirecting_number=5001
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.661: :cc_get_feature_vsa malloc success
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.661: cc_get_feature_vsa count is 3
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.661: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763334784,feature_id:492
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 22:05:33.661: feature_vsa is 691A5C38,featname is 0
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.661: :cc_get_feature_vsa malloc success
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.661: cc_get_feature_vsa count is 4
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.661: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763335456,feature_id:493
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 22:05:33.661: : Generating new featurevsa,inserting it
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 22:05:33.661: feature call forward featname is 3
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 22:05:33.661: feature_vsa is 691A5DF8,featname is 0
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.661: :cc_get_feature_vsa malloc success
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.661: cc_get_feature_vsa count is 5
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.661: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763335008,feature_id:494
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 22:05:33.661: : Generating new featurevsa,inserting it
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 22:05:33.661: feature call forward featname is 3
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 22:05:33.661: :cc_free_feature_vsa freeing 691A5A78
*Feb 24 22:05:33.661: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 22:05:33.661: vsacount in free is 4
*Feb 24 22:05:33.661: //281/263A580A8330/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=19)
*Feb 24 22:05:33.661: //281/263A580A8330/CCAPI/ccCallDisconnect:
Cause Value=19, Call Entry(Responsed=TRUE, Cause Value=19)
*Feb 24 22:05:33.661: //281/263A580A8330/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
*Feb 24 22:05:33.665: //281/263A580A8330/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x7222B574, Tag=0x0, Call Id=281,
Call Entry(Disconnect Cause=19, Voice Class Cause Code=0, Retry Count=0)
*Feb 24 22:05:33.665: //281/263A580A8330/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Feb 24 22:05:33.665: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 22:05:33.665: :cc_free_feature_vsa freeing 691A5B58
*Feb 24 22:05:33.665: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 22:05:33.665: vsacount in free is 3
*Feb 24 22:05:33.665: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 22:05:33.665: vsacount in free is 2
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.669: :cc_get_feature_vsa malloc success
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.669: cc_get_feature_vsa count is 3
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.669: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763335680,feature_id:495
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 22:05:33.669: feature call forward featname is 3
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 22:05:33.669: :cc_free_feature_vsa freeing 691A5DF8
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 22:05:33.669: vsacount in free is 2
*Feb 24 22:05:33.669: //280/263A580A8330/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=1, Params=0x6CBFF9FC, Progress Indication=NULL(0)
*Feb 24 22:05:33.669: //280/263A580A8330/CCAPI/ccCheckClipClir:
In: Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 22:05:33.669: //280/263A580A8330/CCAPI/ccCheckClipClir:
Out: Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 22:05:33.669: //280/263A580A8330/CCAPI/ccCallSetupRequest:
Destination Pattern=2..., Called Number=2000, Digit Strip=FALSE
*Feb 24 22:05:33.669: //280/263A580A8330/CCAPI/ccCallSetupRequest:
Calling Number=4003(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=2000(TON=Unknown, NPI=Unknown),
Redirect Number=5001, Display Info=SECRET1003
Account Number=4003, Final Destination Flag=TRUE,
Guid=8F6A9B48-DA79-11E5-831F-D52F405667DF, Outgoing Dial-peer=1
*Feb 24 22:05:33.669: //280/263A580A8330/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=4003
----- ccCallInfo IE subfields -----
cisco-ani=4003
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=2000
cisco-desttype=0
cisco-destplan=0
cisco-rdie=73
cisco-rdn=5001
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=2 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

*Feb 24 22:05:33.669: //280/263A580A8330/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x69D1B604, Interface Type=3, Destination=, Mode=0x0,
Call Params(Calling Number=4003,(Calling Name=SECRET1003)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=2000(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=1, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.669: :cc_get_feature_vsa malloc success
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.669: cc_get_feature_vsa count is 3
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.669: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763335680,feature_id:496
*Feb 24 22:05:33.669: //282/263A580A8330/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1
*Feb 24 22:05:33.669: //282/263A580A8330/CCAPI/ccCallSetContext:
Context=0x6CBFF9AC
*Feb 24 22:05:33.669: //280/263A580A8330/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=1
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 22:05:33.669: feature call forward featname is 3
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 22:05:33.669: feature_vsa is 691A5DF8,featname is 0
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.669: :cc_get_feature_vsa malloc success
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.669: cc_get_feature_vsa count is 4
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 22:05:33.669: :FEATURE_VSA attributes are: feature_name:0,feature_time:1763335008,feature_id:497
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 22:05:33.669: : Generating new featurevsa,inserting it
*Feb 24 22:05:33.669: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

*Feb 24 22:05:33.669: feature call forward featname is 3
*Feb 24 22:05:33.673: //282/263A580A8330/CCAPI/cc_api_call_disconnected:
Cause Value=47, Interface=0x69D1B604, Call Id=282
*Feb 24 22:05:33.673: //282/263A580A8330/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=47, Retry Count=0)
*Feb 24 22:05:33.673: //282/263A580A8330/CCAPI/cc_api_call_disconnected:
Cause Value=47, Interface=0x69D1B604, Call Id=282
*Feb 24 22:05:33.673: //282/263A580A8330/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=47, Retry Count=0)
*Feb 24 22:05:33.673: //280/263A580A8330/CCAPI/ccCallReleaseResources:
release reserved xcoding resource.
*Feb 24 22:05:33.673: //282/263A580A8330/CCAPI/ccCallSetAAA_Accounting:
Accounting=0, Call Id=282
*Feb 24 22:05:33.673: //282/263A580A8330/CCAPI/ccCallDisconnect:
Cause Value=47, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=47)
*Feb 24 22:05:33.673: //282/263A580A8330/CCAPI/ccCallDisconnect:
Cause Value=47, Call Entry(Responsed=TRUE, Cause Value=47)
*Feb 24 22:05:33.673: //282/263A580A8330/CCAPI/cc_api_call_disconnect_done:
Disposition=-11, Interface=0x69D1B604, Tag=0x0, Call Id=282,
Call Entry(Disconnect Cause=47, Voice Class Cause Code=0, Retry Count=0)
*Feb 24 22:05:33.673: //282/263A580A8330/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Feb 24 22:05:33.673: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 22:05:33.673: :cc_free_feature_vsa freeing 691A5B58
*Feb 24 22:05:33.673: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 22:05:33.673: vsacount in free is 3
*Feb 24 22:05:33.673: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 22:05:33.673: vsacount in free is 2
*Feb 24 22:05:33.673: //280/263A580A8330/CCAPI/ccCallDisconnect:
Cause Value=47, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
*Feb 24 22:05:33.673: //280/263A580A8330/CCAPI/ccCallDisconnect:
Cause Value=47, Call Entry(Responsed=TRUE, Cause Value=47)
*Feb 24 22:05:33.677: //280/263A580A8330/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bKB221A8
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=10002668-497
To: <sip:5001@10.0.185.70>;tag=1000CBD8-17FF
Date: Wed, 24 Feb 2016 22:05:21 GMT
Call-ID: 277BFFA4-DA7511E5-8335D0DA-8C41CEE@10.0.185.71
Timestamp: 1456349641
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Reason: Q.850;cause=47
Content-Length: 0

*Feb 24 22:05:33.685: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:5001@10.0.185.70:5060 SIP/2.0
Via: SIP/2.0/TCP 10.0.185.71:5060;branch=z9hG4bKB221A8
From: "SECRET1003" <sip:4003@10.0.185.71>;tag=10002668-497
To: <sip:5001@10.0.185.70>;tag=1000CBD8-17FF
Date: Wed, 24 Feb 2016 21:34:01 GMT
Call-ID: 277BFFA4-DA7511E5-8335D0DA-8C41CEE@10.0.185.71
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event
Content-Length: 0

*Feb 24 22:05:33.689: //280/263A580A8330/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x69D1B604, Tag=0x0, Call Id=280,
Call Entry(Disconnect Cause=47, Voice Class Cause Code=0, Retry Count=0)
*Feb 24 22:05:33.689: //280/263A580A8330/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Feb 24 22:05:33.689: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 22:05:33.689: :cc_free_feature_vsa freeing 691A5D18
*Feb 24 22:05:33.689: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 22:05:33.689: vsacount in free is 1
*Feb 24 22:05:33.689: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 22:05:33.689: vsacount in free is 0

Check my IM??  Didn't see anything from you.

Thanks to Nadeem Ahmed, he identified the lack of a transcoder between the CME's G.729 codec and the CUE module's G.711 codec.  Problem resolved!

you are welcome CChambleeJr glad issue resolved

Br, Nadeem Please rate all useful post.

Hello,

To add to what Nadeem said "When a call comes in on an SIP trunk and gets forwarded (CFNA / CFB / CFA), then the default behavior is for the CME to send the 302 “Moved Temporarily” SIP message to the Service Provider (SP) proxy. The user portion of the Contact Header in the 302 message might need to be translated to reflect a DID that the SP proxy can route to. The host portion of the Contact Header in the 302 message should be modified to reflect the Address of Record (AOR) using the host-registrar CLI under sip-ua and the b2bua CLI under the VoIP dial peer going to the CUE.

Some SIP proxies might not support this. If so, then you need to add this:"

MS(config)#voice service voip
MS(conf-voi-serv)#no supplementary-service sip moved-temporarily

-Regards,

Kevin

Nadeem Ahmed
Cisco Employee
Cisco Employee

also post the show run and enable debug voice ccapi inout too.

Br, Nadeem Please rate all useful post.
Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: