Solved: CME - Incoming calls ring but caller gets busy signal

Davidwagman1 · ‎05-11-2012

Hi Everyone,

Got the outbound SIP working with my 2851 and call manager express 8. Inbound rings at the proper extension, but the calling phone gets a busy signal. I pulled a SIP trace and it says "Internal Server Error" but I can't figure out the problem, so I'm hoping one of the experts on here can point me in the right direction.

Thanks in advance!

David

Date: Thu, 10 May 2012 13:25:26 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Type: application/sdp
Content-Length: 285

v=0
o=root 7920 7920 IN IP4 74.63.41.218
s=session
c=IN IP4 74.63.41.218
t=0 0
m=audio 16466 RTP/AVP 0 18 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

May 10 09:24:55.889: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 74.63.41.218:5060;branch=z9hG4bK76b5a7c9;rport
From: "5163193019" <sip:5163193019@74.63.41.218>;tag=as0a195cd3
To: <sip:5164038959@96.250.50.2xx:5060>
Date: Thu, 10 May 2012 09:24:55 GMT
Call-ID: 21789578522fa0d02d991cd52d3b083f@74.63.41.218
CSeq: 102 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0


May 10 09:24:55.889: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
[b]SIP/2.0 500 Internal Server Error[/b]
Via: SIP/2.0/UDP 74.63.41.218:5060;branch=z9hG4bK76b5a7c9;rport
From: "5163193019" <sip:5163193019@74.63.41.218>;tag=as0a195cd3
To: <sip:5164038959@96.250.50.2xx:5060>;tag=3EFA410-119D
Date: Thu, 10 May 2012 09:24:55 GMT
Call-ID: 21789578522fa0d02d991cd52d3b083f@74.63.41.218
CSeq: 102 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0


May 10 09:24:55.897: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:5164038959@96.250.50.2xx:5060 SIP/2.0
Via: SIP/2.0/UDP 74.63.41.218:5060;branch=z9hG4bK76b5a7c9;rport
From: "5163193019" <sip:5163193019@74.63.41.218>;tag=as0a195cd3
To: <sip:5164038959@96.250.50.2xx:5060>;tag=3EFA410-119D
Contact: <sip:5163193019@74.63.41.218>
Call-ID: 21789578522fa0d02d991cd52d3b083f@74.63.41.218
CSeq: 102 ACK
User-Agent: VoIPMS/SERAST
Max-Forwards: 70
Remote-Party-ID: "5163193019" <sip:5163193019@74.63.41.218>;privacy=off;screen=no
Content-Length: 0

CONFIG:

------------------ show version ------------------

Cisco IOS Software, 2800 Software (C2800NM-IPVOICEK9-M), Version 15.1(1)T, RELEASE SOFTWARE (fc1)
Technical Support: http://www.cisco.com/techsupport
Copyright (c) 1986-2010 by Cisco Systems, Inc.
Compiled Mon 22-Mar-10 01:25 by prod_rel_team

ROM: System Bootstrap, Version 12.4(13r)T, RELEASE SOFTWARE (fc1)

CME uptime is 8 hours, 31 minutes
System returned to ROM by power-on
System image file is "flash:c2800nm-ipvoicek9-mz.151-1.T.bin"
Last reload type: Normal Reload


This product contains cryptographic features and is subject to United
States and local country laws governing import, export, transfer and
use. Delivery of Cisco cryptographic products does not imply
third-party authority to import, export, distribute or use encryption.
Importers, exporters, distributors and users are responsible for
compliance with U.S. and local country laws. By using this product you
agree to comply with applicable laws and regulations. If you are unable
to comply with U.S. and local laws, return this product immediately.

A summary of U.S. laws governing Cisco cryptographic products may be found at:
http://www.cisco.com/wwl/export/crypto/tool/stqrg.html

If you require further assistance please contact us by sending email to
export@cisco.com.

Cisco 2851 (revision 53.51) with 512000K/12288K bytes of memory.
Processor board ID FTX1212A1DS
2 Gigabit Ethernet interfaces
1 terminal line
4 Voice FXO interfaces
1 cisco service engine(s)
DRAM configuration is 64 bits wide with parity enabled.
239K bytes of non-volatile configuration memory.
250880K bytes of ATA CompactFlash (Read/Write)


License Info:

License UDI:

-------------------------------------------------
Device#       PID               SN
-------------------------------------------------
*0         CISCO2851             FTX1212A1DS     



Configuration register is 0x2102


------------------ show running-config ------------------


Building configuration...



Current configuration : 8958 bytes
!
! Last configuration change at 03:45:25 UTC Fri May 11 2012 by david
!
version 15.1
service timestamps debug datetime msec
service timestamps log datetime msec
no service password-encryption
!
hostname CME
!
boot-start-marker
boot-end-marker
!
enable secret 5 <removed>
enable password <removed>
!
no aaa new-model
no network-clock-participate slot 1 
!
dot11 syslog
ip source-route
!
!
ip cef
no ip dhcp use vrf connected
ip dhcp excluded-address 172.16.1.1 172.16.1.10
!
ip dhcp pool VOICE
   network 172.16.1.0 255.255.255.0
   default-router 172.16.1.1 
   option 150 ip 172.16.1.1 
!
!
ip domain name ipolawgroup.com
ip name-server 4.2.2.2
no ipv6 cef
multilink bundle-name authenticated
!
!
!
!
!
!
voice rtp send-recv
!
voice service voip
 gcid
 clid substitute name
 allow-connections h323 to h323
 allow-connections h323 to sip
 allow-connections sip to h323
 allow-connections sip to sip
 no supplementary-service sip moved-temporarily
 no supplementary-service sip refer
 sip
  e911
  transport switch udp tcp
  asserted-id ppi
  midcall-signaling passthru
  no call service stop
!
voice class codec 1
 codec preference 1 g729r8
 codec preference 2 g711ulaw
 codec preference 3 g711alaw
!
voice class h323 1
  telephony-service ccm-compatible
  ccm-compatible
!
!
!
!
voice translation-rule 2
 rule 1 /105/ /5164038926/
!
voice translation-rule 3
 rule 1 /5164038959/ /105/
!
!
voice translation-profile INCOMING
!
!
voice-card 0
!
voice-card 1
!
crypto pki token default removal timeout 0
!
!
!
!
license udi pid CISCO2851 sn FTX1212A1DS
archive
 log config
  hidekeys
username cisco privilege 15 password 0 <removed>
!
!
!
!
!
!
!
interface GigabitEthernet0/0
 description LAN_INTERFACE
 ip address 172.16.1.1 255.255.255.0
 ip nat inside
 ip virtual-reassembly
 duplex auto
 speed auto
 no mop enabled
!
interface Service-Engine0/1
 ip address 172.16.200.1 255.255.255.252
 service-module ip address 172.16.200.2 255.255.255.252
 service-module ip default-gateway 172.16.200.1
!
interface GigabitEthernet0/1
 description WAN_INTERFACE
 ip address xx.xxx.xx.xxx 255.255.255.0
 ip nat outside
 ip virtual-reassembly
 duplex auto
 speed auto
 no mop enabled
!
ip forward-protocol nd
!
ip http server
ip http access-class 10
ip http authentication local
no ip http secure-server
ip http path flash:
!
ip nat inside source list 1 interface GigabitEthernet0/1 overload
ip route 0.0.0.0 0.0.0.0 xx.xxx.xx.x
ip route 10.10.1.0 255.255.255.0 172.16.1.254
!
access-list 1 permit 172.16.1.0 0.0.0.255
dialer-list 1 protocol ip permit
!
!
tftp-server flash:term06.default.loads
tftp-server flash:term41.default.loads
tftp-server flash:P00308010200.bin alias P00308010200.bin
tftp-server flash:P00308010200.loads alias P00308010200.loads
tftp-server flash:P00308010200.sb2 alias P00308010200.sb2
tftp-server flash:P00308010200.sbn alias P00308010200.sbn
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:/Ringtones/DistinctiveRingList.xml alias DistinctiveRingList.xml
tftp-server flash:/Ringtones/AreYouThereF.raw alias AreYouThereF.raw
tftp-server flash:/Ringtones/FilmScore.raw alias FilmScore.raw
tftp-server flash:/Ringtones/HarpSynth.raw alias HarpSynth.raw
tftp-server flash:/Ringtones/Jamaica.raw alias Jamaica.raw
tftp-server flash:/Ringtones/KotoEffect.raw alias KotoEffect.raw
tftp-server flash:/Ringtones/MusicBox.raw alias MusicBox.raw
tftp-server flash:/Ringtones/Piano1.raw alias Piano1.raw
tftp-server flash:/Ringtones/Piano2.raw alias Piano2.raw
tftp-server flash:/Ringtones/Pop.raw alias Pop.raw
tftp-server flash:/Ringtones/Pulse1.raw alias Pulse1.raw
tftp-server flash:/Ringtones/Ring1.raw alias Ring1.raw
tftp-server flash:/Ringtones/Ring2.raw alias Ring2.raw
tftp-server flash:/Ringtones/Ring3.raw alias Ring3.raw
tftp-server flash:/Ringtones/Ring4.raw alias Ring4.raw
tftp-server flash:/Ringtones/Ring6.raw alias Ring6.raw
tftp-server flash:/Ringtones/Ring7.raw alias Ring7.raw
tftp-server flash:/Ringtones/Sax1.raw alias Sax1.raw
tftp-server flash:/Ringtones/Sax2.raw alias Sax2.raw
tftp-server flash:/Ringtones/Vibe.raw alias Vibe.raw
tftp-server flash:/Ringtones/RingList.xml alias RingList.xml
tftp-server flash:/Ringtones/Analog1.raw alias Analog1.raw
tftp-server flash:/Ringtones/Analog2.raw alias Analog2.raw
tftp-server flash:/Ringtones/AreYouThere.raw alias AreYouThere.raw
tftp-server flash:/Ringtones/Bass.raw alias Bass.raw
tftp-server flash:/Ringtones/CallBack.raw alias CallBack.raw
tftp-server flash:/Ringtones/Chime.raw alias Chime.raw
tftp-server flash:/Ringtones/Classic1.raw alias Classic1.raw
tftp-server flash:/Ringtones/Classic2.raw alias Classic2.raw
tftp-server flash:/Ringtones/ClockShop.raw alias ClockShop.raw
tftp-server flash:/Ringtones/Drums1.raw alias Drums1.raw
tftp-server flash:/Ringtones/Drums2.raw alias Drums2.raw
!
control-plane
!
!
voice-port 1/0/0
 connection plar opx 102
 caller-id enable
!
voice-port 1/0/1
!
voice-port 1/0/2
!
voice-port 1/0/3
!
ccm-manager music-on-hold
!
!
!
dial-peer voice 100 voip
 description DIAL_PEER_TO_CUE
 destination-pattern 77[5-9]
 session protocol sipv2
 session target ipv4:172.16.200.2
 dtmf-relay sip-notify
 codec g711ulaw
 no vad
!
dial-peer voice 10 pots
 description POTS_DIAL_PEER_OUTGOING
 destination-pattern 1[2-9]..[2-9]......
 port 1/0/0
!
dial-peer voice 1 voip
 incoming called-number 51640389..
 voice-class sip asserted-id ppi
 no voice-class sip block 180
 no voice-class sip block 183
 no voice-class sip block 181
 voice-class sip pass-thru headers unsupp
 voice-class sip pass-thru content unsupp
 voice-class sip pass-thru content sdp
 dtmf-relay rtp-nte
!
dial-peer voice 2 voip
 destination-pattern [2-9]..[2-9]......
 session protocol sipv2
 session target ipv4:74.63.41.218
 session transport udp
 voice-class sip asserted-id ppi
 no voice-class sip block 180
 no voice-class sip block 183
 no voice-class sip block 181
 voice-class sip pass-thru headers unsupp
 voice-class sip pass-thru content unsupp
 voice-class sip pass-thru content sdp
 dtmf-relay rtp-nte
 codec g711ulaw
!
!
!
telephony-service
 authentication credential cisco cisco
 max-ephones 30
 max-dn 45
 ip source-address 172.16.1.1 port 2000
 system message IPO Law Group
 url services http://172.16.200.2/voiceview/common/login.do 
 url authentication http://172.16.200.1/CCMCIP/authenticate.asp  
 cnf-file location flash:
 load 7960-7940 P00308010200
 load 7941 term41.default.loads
 load 7942 term42.default.loads
 load 7945 term70.default.loads
 load 7961 term06.default.loads
 load 7962 term62.default.loads
 load 7965 term71.default.loads
 max-conferences 4 gain -6
 moh flash:music-on-hold.au
 multicast moh 239.1.1.1 port 2000
 web admin system name cisco password <removed>
 dn-webedit 
 time-webedit 
 transfer-system full-consult
 create cnf-files version-stamp Jan 01 2002 00:00:00
!
!
ephone-dn  1  dual-line
 number 101
 call-forward noan 777 timeout 16
!
!
ephone-dn  2  dual-line
 number 102
 call-forward busy 777
 call-forward noan 777 timeout 16
!
!
ephone-dn  3  dual-line
 number 103
 call-forward busy 777
 call-forward noan 777 timeout 16
!
!
ephone-dn  4  dual-line
 number 104
!
!
ephone-dn  5  dual-line
 number 5164038959
 description DID 1 VOIPMS
!
!
ephone-dn  6  dual-line
 number 106
!
!
ephone-dn  7  dual-line
 number 107
!
!
ephone-dn  8  dual-line
 number 108
!
!
ephone-dn  9  dual-line
 number 109
!
!
ephone-dn  10  dual-line
 number 110
!
!
ephone-dn  11  dual-line
 number 111
!
!
ephone-dn  12  dual-line
 number 112
!
!
ephone-dn  13  dual-line
 number 113
!
!
ephone-dn  14  dual-line
 number 114
!
!
ephone-dn  15  dual-line
 number 115
!
!
ephone-dn  16  dual-line
 number 116
!
!
ephone-dn  17  dual-line
 number 117
!
!
ephone-dn  18  dual-line
 number 118
!
!
ephone-dn  19  dual-line
 number 119
!
!
ephone-dn  20  dual-line
 number 120
!
!
ephone-dn  21  dual-line
 number 121
!
!
ephone-dn  22  dual-line
 number 122
!
!
ephone-dn  23  dual-line
 number 123
!
!
ephone-dn  24  dual-line
 number 124
!
!
ephone-dn  25  dual-line
 number 125
!
!
ephone-dn  26  dual-line
 number 126
!
!
ephone-dn  27  dual-line
 number 127
!
!
ephone-dn  28  dual-line
 number 128
!
!
ephone-dn  29  dual-line
 number 129
!
!
ephone-dn  30  dual-line
 number 130
!
!
ephone  2
 mac-address 0013.60B5.26F1
 username "user2"
 type 7960
 button  1:2
!
!
!
ephone  3
 mac-address 000E.D759.515C
 type 7940
 button  1:3 2:5
!
!
!
line con 0
line aux 0
line 258
 no activation-character
 no exec
 transport preferred none
 transport input all
 transport output pad telnet rlogin lapb-ta mop udptn v120 ssh
line vty 0 4
 password <removed>
 login local
 transport input ssh
!
scheduler allocate 20000 1000
end

Ayodeji Okanlawon · ‎05-16-2012

ok while you are doing that..

can you try to remove this commands on dial-peer 1, please add codec 711ulaw back to it.

voice-class sip pass-thru headers unsupp

voice-class sip pass-thru content unsupp

voice-class sip pass-thru content sdp

Please rate all useful posts

View solution in original post

TunNyuntMoe · ‎05-11-2012

try this:

voice service voip

ip address trusted list

ipv4 x.x.x.x x.x.x.x

Davidwagman1 · ‎05-11-2012

Thanks for the reply Tun Moe. Its not taking the commands:

TunNyuntMoe · ‎05-11-2012

sorry David. the command I suggested only work for v8.1 and after.

I think you have v8.0

can you do show sip-ua status/stat

Thanks,

Davidwagman1 · ‎05-11-2012

Yes, I'm on 8.0

CME#show sip-ua status

SIP User Agent Status

SIP User Agent for UDP : ENABLED

SIP User Agent for TCP : ENABLED

SIP User Agent for TLS over TCP : ENABLED

SIP User Agent bind status(signaling): DISABLED

SIP User Agent bind status(media): DISABLED

SIP early-media for 180 responses with SDP: ENABLED

SIP max-forwards : 70

SIP DNS SRV version: 2 (rfc 2782)

NAT Settings for the SIP-UA

Role in SDP: NONE

Check media source packets: DISABLED

Maximum duration for a telephone-event in NOTIFYs: 2000 ms

SIP support for ISDN SUSPEND/RESUME: ENABLED

Redirection (3xx) message handling: ENABLED

Reason Header will override Response/Request Codes: DISABLED

Out-of-dialog Refer: DISABLED

Presence support is DISABLED

protocol mode is ipv4

SDP application configuration:

Version line (v=) required

Owner line (o=) required

Timespec line (t=) required

Media supported: audio video image

Network types supported: IN

Address types supported: IP4 IP6

Transport types supported: RTP/AVP udptl

TunNyuntMoe · ‎05-11-2012

can you please add

codec g711ulaw

under

dial-peer voice 1 voip

and test it again

thanks

Davidwagman1 · ‎05-11-2012

Same symptoms, the extension rings and the calling phone has a busy signal.

!
dial-peer voice 1 voip
 incoming called-number 51640389..
 voice-class sip asserted-id ppi
 no voice-class sip block 180
 no voice-class sip block 183
 no voice-class sip block 181
 voice-class sip pass-thru headers unsupp
 voice-class sip pass-thru content unsupp
 voice-class sip pass-thru content sdp
 dtmf-relay rtp-nte
 codec g711ulaw
!

Davidwagman1 · ‎05-14-2012

Have a more detailed sip trace, still need help please!

CME#
CME#
.May 14 16:44:09.684: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [74.63.41.218]:5060
.May 14 16:44:09.684: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
.May 14 16:44:09.684: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
.May 14 16:44:09.684: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received: 
INVITE sip:xxxxxxxx60@xx.xxx.xx.xxx:5060 SIP/2.0 
Via: SIP/2.0/UDP 74.63.41.218:5060;branch=z9hG4bK09426ff8;rport 
From: "xxxxxxxx26" ;tag=as123c0943 
To:  
Contact:  
Call-ID: 372c3b68582552781c93894f3331c819@74.63.41.218 
CSeq: 102 INVITE 
User-Agent: VoIPMS/SERAST 
Max-Forwards: 70 
Remote-Party-ID: "xxxxxxxx26" ;privacy=off;screen=no 
Date: Mon, 14 May 2012 16:45:46 GMT 
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO 
Supported: replaces 
Content-Type: application/sdp 
Content-Length: 285 
 
v=0 
o=root 7920 7920 IN IP4 74.63.41.218 
s=session 
c=IN IP4 74.63.41.218 
t=0 0 
m=audio 11968 RTP/AVP 0 18 101 
a=rtpmap:0 PCMU/8000 
a=rtpmap:18 G729/8000 
a=fmtp:18 annexb=no 
a=rtpmap:101 telephone-event/8000 
a=fmtp:101 0-16 
a=silenceSupp:off - - - - 
a=ptime:20 
a=sendrecv 

.May 14 16:44:09.684: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
.May 14 16:44:09.688: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x4871BFB8) with key=[9] to table
.May 14 16:44:09.688: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 74.63.41.218,Port 5060, Transport 1, SentBy Port 5060
.May 14 16:44:09.688: //-1/DCCBEED18050/SIP/State/sipSPIChangeState: 0x4871BFB8 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
.May 14 16:44:09.688: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 74.63.41.218,Port 5060, Transport 1, SentBy Port 5060
.May 14 16:44:09.688: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone edt to SIP default timezone = GMT
.May 14 16:44:09.688: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 74.63.41.218,Port 5060, Transport 1, SentBy Port 5060
.May 14 16:44:09.688: //-1/DCCBEED18050/SIP/Info/sipSPISetInfoFromRpid: Received current remote name: xxxxxxxx26, current remote number: xxxxxxxx26
.May 14 16:44:09.688: //-1/DCCBEED18050/SIP/Info/sipSPISetInfoFromRpid: Received ;screen=no ;privacy=off -> Setting Octet3A 0x80, extended_privacy 0x00
.May 14 16:44:09.688: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
.May 14 16:44:09.688: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCSTA: No CSTA found in inbound container
.May 14 16:44:09.688: //-1/DCCBEED18050/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
.May 14 16:44:09.688: //-1/DCCBEED18050/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x4871BFB8 key=372c3b68582552781c93894f3331c819@74.63.41.218xxxxxxxx60
.May 14 16:44:09.688: //-1/DCCBEED18050/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id
.May 14 16:44:09.688: //-1/DCCBEED18050/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: xxxxxxxx60
.May 14 16:44:09.688: //-1/DCCBEED18050/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: xxxxxxxx26
.May 14 16:44:09.688: //-1/DCCBEED18050/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name xxxxxxxx26, number xxxxxxxx26, Calling oct3 0x00, oct_3a 0x80, Called number xxxxxxxx60
.May 14 16:44:09.688: //-1/DCCBEED18050/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : xxxxxxxx26
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIGetCallConfig: Peer tag 1 matched for incoming call
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIGetCallConfig: This call is being treated for E911
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIGetCallConfig: Not using Voice Class Codec
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIGetCallConfig: Checking Video Type Rate=-1 video_codec_allowed=1F
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIGetCallConfig: xcoder high-density disabled
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIGetCallConfig: Flow Mode set to FLOW_THROUGH
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIGetCallConfig: Media forking disabled
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIContinueNewMsgInvite: Calling name xxxxxxxx26, number xxxxxxxx26, Calling oct3 0x00, oct_3a 0x80, ext_priv 0x00, Called number xxxxxxxx60, oct3 0x00
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIValidateRequestUri: Not Enabled
.May 14 16:44:09.692: //-1/DCCBEED18050/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
.May 14 16:44:09.692: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_IsSDPPassthruEnabled:  - 1
.May 14 16:44:09.692: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:2 tag:0
.May 14 16:44:09.692: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Resource-Priority
.May 14 16:44:09.692: //27/DCCBEED18050/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
.May 14 16:44:09.692: //27/DCCBEED18050/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container
.May 14 16:44:09.692: //27/DCCBEED18050/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found
.May 14 16:44:09.692: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_ProcessSDPForPthru: 
.May 14 16:44:09.692: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_GetContentSDPForPthru: Getting content to pass-through
.May 14 16:44:09.692: //27/DCCBEED18050/SIP/Media/sipSPI_ipip_GetContentSDPForPthru: Updated SDP from inbound  container:285
.May 14 16:44:09.692: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_ProcessPthruSDPInInvite: 
.May 14 16:44:09.692: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_DoPthruMediaNegotiation: 
SIP: Attribute mid, level 1 instance 1 not found.
.May 14 16:44:09.692: //27/DCCBEED18050/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = xx.xxx.xx.xxx
.May 14 16:44:09.692: //27/DCCBEED18050/SIP/State/sipSPIChangeStreamState: Stream (callid =  -1)  State changed from (STREAM_DEAD) to (STREAM_ADDING) 
.May 14 16:44:09.692: //27/DCCBEED18050/SIP/Info/sipSPICompareSDP: Comparison not needed for first offer sdp
.May 14 16:44:09.692: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISipSdpFree: 
.May 14 16:44:09.692: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_ipip_FreeSipRawSdp: no sdp to free
.May 14 16:44:09.692: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_ipip_FreeSipRawSdp: no sdp to free
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Media/sipSPIReplaceSDP: Main stream got changed & it's a Flow thru
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Media/sipSPIProcessRtpSessions: sipSPIProcessRtpSessions
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 27) to the VOIP RTP library
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Media/sipSPIAddStream: Reserved port 16610 for rtp/rtcp
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = xx.xxx.xx.xxx
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
     laddr = xx.xxx.xx.xxx, lport = 16610, raddr = 74.63.41.218, rport=11968, do_rtcp=TRUE
     src_callid = 27, dest_callid = -1, stream type = voice+dtmf, stream direction = SENDRECV
     media_ip_addr = 74.63.41.218, vrf tableid = 0 media_addr_type = 1
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/sipSPICreateRtpSession: sess: 476A6480 do_rtcp:1
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Media/sipSPICreateRtpSession: stun is disabled
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Error/sipSPIUpdateRtcpSession: Unable to update remote media ip address to,application, proceed further
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Media/sipSPIAddStream: AddStream in idle state to open a 'recvonly' media session
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/State/sipSPIChangeStreamState: Stream (callid =  27)  State changed from (STREAM_ADDING) to (STREAM_ACTIVE) 
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/sipSPIUpdateSrcSdpFixedPart: RTP port already reserved for stream 1, src_port=16610
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = xx.xxx.xx.xxx
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_ReportPthruMediaToPeer: 
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_ReportPthruMediaToPeer: 
CCSIP: Unable to send OPEN_CHANNEL_IND
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_UpdPthruCallWithSdpInfo: 
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = 372c3b68582552781c93894f3331c819@74.63.41.218
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:2 tag:0
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Date
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Allow
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header From
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Supported
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Remote-Party-ID
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Content-Length
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header User-Agent
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header To
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Contact
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Content-Type
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Call-ID
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Via
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header CSeq
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Max-Forwards
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled:  - 1
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_GetPassthruContent: Found Single Content in SIP Msg
.May 14 16:44:09.696: //-1/xxxxxxxxxxxx/SIP/Info/sipSPI_ipip_IsUnsupportedContentType: Content-Type application/sdp matched
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: No content in SIP Msg or Error
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_CopySdpToContainer: initialInvite:TRUE
.May 14 16:44:09.696: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_CopySdpToContainer: sdp being passed through;v=0 
o=root 7920 7920 IN IP4 74.63.41.218 
s=session 
c=IN IP4 74.63.41.218 
t=0 0 
m=audio 11968 RTP/AVP 0 18 101 
a=rtpmap:0 PCMU/8000 
a=rtpmap:18 G729/8000 
a=fmtp:18 annexb=no 
a=rtpmap:101 telephone-event/8000 
a=fmtp:101 0-16 
a=silenceSupp:off - - - - 
a=ptime:20 
a=sendrecv 

.May 14 16:44:09.700: //27/DCCBEED18050/SIP/Info/sipSPIShrlCall: Check peer: 1 for Shared-Line call, callid: 27
.May 14 16:44:09.700: //27/DCCBEED18050/SIP/Info/ccsip_set_bearer_capability: 
   Bearer Capability: Speech (0x00)
.May 14 16:44:09.700: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
.May 14 16:44:09.700: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
.May 14 16:44:09.700: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message

.May 14 16:44:09.700: //27/DCCBEED18050/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS
.May 14 16:44:09.700: //27/DCCBEED18050/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 1B to table
.May 14 16:44:09.700: //27/DCCBEED18050/SIP/Info/sipSPISendInviteResponse: Associated container=0x4934D824 to Invite Response 100
.May 14 16:44:09.700: //27/DCCBEED18050/SIP/Transport/sipSPITransportSendMessage: msg=0x4790D6B0, addr=74.63.41.218, port=5060, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x0
.May 14 16:44:09.700: //27/DCCBEED18050/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
.May 14 16:44:09.700: //27/DCCBEED18050/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
.May 14 16:44:09.700: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x4790D6B0, addr=74.63.41.218, port=5060, connId=0 for UDP
.May 14 16:44:09.700: //27/DCCBEED18050/SIP/State/sipSPIChangeState: 0x4871BFB8 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (STATE_RECD_INVITE, SUBSTATE_NONE)
.May 14 16:44:09.700: //27/DCCBEED18050/SIP/Info/sipSPIProcessContactInfo: Previous Hop 74.63.41.218:5060
.May 14 16:44:09.704: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDING
.May 14 16:44:09.704: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler:  
.May 14 16:44:09.704: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 164)
.May 14 16:44:09.704: //27/DCCBEED18050/SIP/Info/ccsip_event_handler: 
 ccsip_event_handler: peer ID 28 chans 0x4B09B538 event 164 flags 0x40001C 0x100 0x601 data 0x4B09B538
.May 14 16:44:09.704: //27/DCCBEED18050/SIP/Info/ccsip_event_handler: 
 ccsip_event_handler: CC_EV_H245_SET_MODE: peer ID 28 chans 0x4B09B538 event 164 flags 0x40001C 0x100 0x601 data 0x4B09B538, type = 1
SIP: Attribute mid, level 1 instance 1 not found.
.May 14 16:44:09.708: //27/DCCBEED18050/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
.May 14 16:44:09.708: //27/DCCBEED18050/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = xx.xxx.xx.xxx
.May 14 16:44:09.708: //27/DCCBEED18050/SIP/State/sipSPIChangeStreamState: Stream (callid =  27)  State changed from (STREAM_ACTIVE) to (STREAM_ADDING) 
.May 14 16:44:09.708: //27/DCCBEED18050/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-TDM
.May 14 16:44:09.708: //27/DCCBEED18050/SIP/Error/ccsip_event_handler: It is not supported to set SDPpassthrough for non SIP-SIP callsThe call will be disconnected
.May 14 16:44:09.708: //27/DCCBEED18050/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table.
.May 14 16:44:09.708: //27/DCCBEED18050/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x4871BFB8 key=372c3b68582552781c93894f3331c819@74.63.41.21860F2428-2506
.May 14 16:44:09.708: //27/DCCBEED18050/SIP/Info/sipSPISendInviteResponse: Associated container=0x4934C95C to Invite Response 500
.May 14 16:44:09.708: //27/DCCBEED18050/SIP/Transport/sipSPITransportSendMessage: msg=0x476A8EAC, addr=74.63.41.218, port=5060, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x4185D118
.May 14 16:44:09.708: //27/DCCBEED18050/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
.May 14 16:44:09.708: //27/DCCBEED18050/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
.May 14 16:44:09.708: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x476A8EAC, addr=74.63.41.218, port=5060, connId=0 for UDP
.May 14 16:44:09.708: //27/DCCBEED18050/SIP/Info/sentErrResDisconnecting: Sent an 3456XX Error Response
.May 14 16:44:09.708: //27/DCCBEED18050/SIP/State/sipSPIChangeState: 0x4871BFB8 : State change from (STATE_RECD_INVITE, SUBSTATE_NONE)  to (STATE_DISCONNECTING, SUBSTATE_NONE)
.May 14 16:44:09.708: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 3
.May 14 16:44:09.708: //27/DCCBEED18050/SIP/Info/act_ignore_event: Ignoring unexpected event 3 (SIPSPI_EV_CC_CALL_PROCEEDING) in state 9 (STATE_DISCONNECTING) substate 0 (SUBSTATE_NONE)
.May 14 16:44:09.716: //27/DCCBEED18050/SIP/Info/sip_gw_video_handle_alert: Video caps are not detected in the caps posted by peer leg
.May 14 16:44:09.716: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_ALERTING
.May 14 16:44:09.716: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_MEDIA_EVENT
.May 14 16:44:09.716: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 5
.May 14 16:44:09.716: //27/DCCBEED18050/SIP/Error/sipSPIAddCiscoGcid: Fatal Error in parsing CCB/Msg
.May 14 16:44:09.716: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIStoreTunnelData: Container /RawMessage Absent
.May 14 16:44:09.716: //27/DCCBEED18050/SIP/Error/sipSPI_ipip_set_history_info_header: Not SIP2SIP mode 
.May 14 16:44:09.716: //27/DCCBEED18050/SIP/Info/act_ignore_event: Ignoring unexpected event 5 (SIPSPI_EV_CC_CALL_ALERTING) in state 9 (STATE_DISCONNECTING) substate 0 (SUBSTATE_NONE)
.May 14 16:44:09.716: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 30
.May 14 16:44:09.716: //27/DCCBEED18050/SIP/Error/sipSPIPreProcessCallerIDMediaEvent: Don't expect a callerid update in STATE_DISCONNECTING
.May 14 16:44:09.716: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIPreProcessCallerIDMediaEvent: Updated Connected Party Name:  Updated Connected Party Number: xxxxxxxx60 Updated Connected Party Oct3a: 0x00
.May 14 16:44:09.716: //27/DCCBEED18050/SIP/Info/sipSPIShrlGetInstanceInfo: Obtained the call instance 0 for non-shared-line '' with callid: 27
.May 14 16:44:09.716: //27/DCCBEED18050/SIP/Info/act_handle_app_media_event: method = 109 state = 9
.May 14 16:44:09.716: //27/DCCBEED18050/SIP/Info/act_handle_app_media_event: Received media sip event SIP_REQUEST_OFFER
.May 14 16:44:09.716: //27/DCCBEED18050/SIP/Info/sipSPICacheEvent: Clear UPDATE flags
.May 14 16:44:09.716: //27/DCCBEED18050/SIP/Error/sact_app_media_event_send_request: Cannot send UPDATE without calling ccsip_api_update_allowed
.May 14 16:44:09.720: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent: 
SIP/2.0 100 Trying 
Via: SIP/2.0/UDP 74.63.41.218:5060;branch=z9hG4bK09426ff8;rport 
From: "xxxxxxxx26" ;tag=as123c0943 
To:  
Date: Mon, 14 May 2012 16:44:09 GMT 
Call-ID: 372c3b68582552781c93894f3331c819@74.63.41.218 
CSeq: 102 INVITE 
Allow-Events: telephone-event 
Server: Cisco-SIPGateway/IOS-12.x 
Content-Length: 0 
 

.May 14 16:44:09.720: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent: 
SIP/2.0 500 Internal Server Error 
Via: SIP/2.0/UDP 74.63.41.218:5060;branch=z9hG4bK09426ff8;rport 
From: "xxxxxxxx26" ;tag=as123c0943 
To: ;tag=60F2428-2506 
Date: Mon, 14 May 2012 16:44:09 GMT 
Call-ID: 372c3b68582552781c93894f3331c819@74.63.41.218 
CSeq: 102 INVITE 
Allow-Events: telephone-event 
Server: Cisco-SIPGateway/IOS-12.x 
Content-Length: 0 
 

.May 14 16:44:09.724: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [74.63.41.218]:5060
.May 14 16:44:09.724: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
.May 14 16:44:09.724: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
.May 14 16:44:09.724: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received: 
ACK sip:xxxxxxxx60@xx.xxx.xx.xxx:5060 SIP/2.0 
Via: SIP/2.0/UDP 74.63.41.218:5060;branch=z9hG4bK09426ff8;rport 
From: "xxxxxxxx26" ;tag=as123c0943 
To: ;tag=60F2428-2506 
Contact:  
Call-ID: 372c3b68582552781c93894f3331c819@74.63.41.218 
CSeq: 102 ACK 
User-Agent: VoIPMS/SERAST 
Max-Forwards: 70 
Remote-Party-ID: "xxxxxxxx26" ;privacy=off;screen=no 
Content-Length: 0 
 

.May 14 16:44:09.724: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x4871BFB8
.May 14 16:44:09.728: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 74.63.41.218,Port 5060, Transport 1, SentBy Port 5060
.May 14 16:44:09.728: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone edt to SIP default timezone = GMT
.May 14 16:44:09.728: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 74.63.41.218,Port 5060, Transport 1, SentBy Port 5060
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Info/sipSPISetInfoFromRpid: Received current remote name: xxxxxxxx26, current remote number: xxxxxxxx26
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Info/sipSPISetInfoFromRpid: Received ;screen=no ;privacy=off -> Setting Octet3A 0x80, extended_privacy 0x00
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Info/sipSPIIcpifUpdate: CallState: 2 Playout: 0 DiscTime:10165561 ConnTime 0
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Media/sipSPIDestroyRtpSession: stream:476A568C
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/State/sipSPIChangeState: 0x4871BFB8 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE)  to (STATE_DEAD, SUBSTATE_NONE)
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Call/sipSPICallInfo: 
The Call Setup Information is:
Call Control Block (CCB) : 0x4871BFB8
State of The Call        : STATE_DEAD
TCP Sockets Used         : NO
Calling Number           : xxxxxxxx26
Called Number            : xxxxxxxx60
Source IP Address (Sig  ): xx.xxx.xx.xxx
Destn SIP Req Addr:Port  : 74.63.41.218:5060
Destn SIP Resp Addr:Port : 74.63.41.218:5060
Destination Name         : 74.63.41.218

.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Call/sipSPIMediaCallInfo: 
Number of Media Streams: 1
Media Stream             : 1
Negotiated Codec         : Passthrough
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): xx.xxx.xx.xxx
Source IP Port    (Media): 16610
Destn  IP Address (Media): 74.63.41.218
Destn  IP Port    (Media): 11968
Orig Destn IP Address:Port (Media): [ - ]:0

.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Call/sipSPICallInfo: 
Disconnect Cause (CC)    : 0
Disconnect Cause (SIP)   : 500

.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 1B
.May 14 16:44:09.728: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[9] removed.
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x4871BFB8 key=372c3b68582552781c93894f3331c819@74.63.41.218xxxxxxxx60
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x4871BFB8 key=372c3b68582552781c93894f3331c819@74.63.41.21860F2428-2506
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Info/sipSPIStopRequestPendingTimer: Stopping Request Pending Timer
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Info/ccsip_qos_cleanup: Entry
.May 14 16:44:09.728: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISipSdpFree: 
.May 14 16:44:09.728: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_ipip_FreeSipRawSdp: no sdp to free
.May 14 16:44:09.728: //-1/xxxxxxxxxxxx/SIP/Info/sipSPI_ipip_FreeSipRawSdp: sdp_ptr:0x48FA998C
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
.May 14 16:44:09.728: //27/DCCBEED18050/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 4871BFB8
.May 14 16:44:09.728: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[9]
.May 14 16:44:13.792: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_call_statistics: ccb NULL, or stats request pending.
.May 14 16:44:13.792: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
.May 14 16:44:13.792: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8
.May 14 16:44:13.792: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_spi_process_ccapi_event: CCB not found for application event 8 withcallID: 27

TunNyuntMoe · ‎05-15-2012

please try following and test it again:

voice service voip

address-hiding

Davidwagman1 · ‎05-15-2012

Thanks for the reply, same symptoms. Would you like me to post a debug and an updated config?

Best,

David

TunNyuntMoe · ‎05-15-2012

yes please do.

can you also do debug for outgoing connection which you said is fine, right?

Davidwagman1 · ‎05-15-2012

I've linked incoming and outgoing debug ccsip all logs. Ph #s and IP addresses descriptively santized.

Incoming Log

Outgoing Log

Ayodeji Okanlawon · ‎05-16-2012

Its diffcult to troubleshoot your issue, beacuse you have hidden your ip addresses. With SIP traces, the ips are important to kno where the call is sent to etc. I have notice that you are doing NAT. this is why its important to know what IP the call is sent to. You can send me a private message with the full traces. But let me know if you send it. NAT and SIP dont work well..so bear that in mind

Please rate all useful posts

Davidwagman1 · ‎05-16-2012

PM sent with the logs, thanks aokanlawon.

The 2851 is doing NAT, but the voice is the only thing on the router, and the phones are the only devices behind the router.

Ayodeji Okanlawon · ‎05-16-2012

David,

I see that the error occurs when the gateway attempts to look for the dialled number 51......

Looking at your config, no such number is matched? Where is this number?

Please rate all useful posts