09-06-2010 07:27 AM - edited 03-16-2019 12:38 AM
Hi all - I think I have a codec mismatch problem but I can't figure it out. I have a CME installed on a mobile truck as part of the Cisco IMICS solution. So basically the CME is using SIP trunks over a satellite connection to the SIP carrier. I have four DIDs that translate to four 4-digit extensions. When I place a call to one of the DIDs the IP phone (7970) rings but when I pick up the phone I get dead air. I suspect a codec mismatch. My SIP carrier is configured to us G.729. I have a dspfarm configure for transcoding but I must be missing something. Config is below. Any ideas?
version 12.4
service timestamps debug datetime msec
service timestamps log datetime msec
no service password-encryption
!
hostname HQ-RTR
!
boot-start-marker
boot system flash:c3845-advipservicesk9-mz.124-11.T1.bin
boot system flash c3845-adventerprisek9-mz.124-11.XJ4.bin
boot-end-marker
!
logging buffered 51200 warnings
!
no aaa new-model
clock timezone pdt -8
ip dhcp relay information policy keep
ip dhcp relay information trust-all
no ip dhcp use vrf connected
!
ip cef
!
!
!
multilink bundle-name authenticated
!
voice-card 0
dspfarm
dsp services dspfarm
!
!
!
voice call carrier capacity active
!
voice service pots
!
voice service voip
allow-connections h323 to h323
allow-connections h323 to sip
allow-connections sip to h323
allow-connections sip to sip
sip
bind control source-interface Satellite1/0
bind media source-interface Satellite1/0
!
!
voice class codec 1
codec preference 1 g729r8
!
!
!
!
!
!
!
!
!
!
!
voice register global
mode cme
max-dn 720
max-pool 240
!
!
voice translation-rule 1
rule 1 /6175555001/ /5001/
rule 2 /6175555002/ /5002/
rule 3 /6175555003/ /5003/
rule 4 /6175555004/ /5004/
!
!
voice translation-profile SAT
translate called 1
!
!
!
crypto pki trustpoint TP-self-signed-4229311208
enrollment selfsigned
subject-name cn=IOS-Self-Signed-Certificate-4229311208
revocation-check none
rsakeypair TP-self-signed-4229311208
!
!
crypto pki certificate chain TP-self-signed-4229311208
certificate self-signed 01 nvram:IOS-Self-Sig#8.cer
!
!
vtp mode transparent
!
!
vlan 150
name WiredData
!
vlan 200
name Servers
!
vlan 250
name WiredVoice
!
vlan 350
name WLANData
!
vlan 450
name WLANVoice
!
!
bridge irb
!
!
!
!
interface GigabitEthernet0/0
ip address 10.2.5.5 255.255.255.0
duplex auto
speed auto
media-type sfp
no keepalive
!
interface GigabitEthernet0/1
ip dhcp relay information trusted
ip dhcp relay information check-reply
ip dhcp relay information policy-action keep
ip address 192.168.65.2 255.255.255.0
duplex auto
speed auto
media-type rj45
no keepalive
!
interface Dot11Radio0/3/0
no ip address
shutdown
speed basic-1.0 basic-2.0 basic-5.5 6.0 9.0 basic-11.0 12.0 18.0 24.0 36.0 48.0
54.0
station-role root
!
interface Dot11Radio0/3/1
no ip address
shutdown
speed basic-6.0 9.0 basic-12.0 18.0 basic-24.0 36.0 48.0 54.0
station-role root
!
interface Satellite1/0
ip address 24.11.70.246 255.255.255.252
ip nat outside
ip virtual-reassembly
service-module ip address 24.11.70.245 255.255.255.252
!
interface Content-Engine2/0
no ip address
shutdown
!
interface wlan-controller3/0
ip address 192.168.103.1 255.255.255.0
!
interface wlan-controller3/0.350
description WLANData
encapsulation dot1Q 350
bridge-group 35
!
interface wlan-controller3/0.450
description WLANVoice
encapsulation dot1Q 450
bridge-group 45
!
interface GigabitEthernet4/0
description SwitchModule
ip address 192.168.104.1 255.255.255.0
bridge-group 1
!
interface GigabitEthernet4/0.150
description WiredData
encapsulation dot1Q 150
bridge-group 15
!
interface GigabitEthernet4/0.200
description WiredData
encapsulation dot1Q 200
bridge-group 20
!
interface GigabitEthernet4/0.250
description WiredData
encapsulation dot1Q 250
ip nat inside
ip nat enable
ip virtual-reassembly
bridge-group 25
!
interface GigabitEthernet4/0.350
description WLANData
encapsulation dot1Q 350
bridge-group 35
!
interface GigabitEthernet4/0.450
description WLANVoice
encapsulation dot1Q 450
bridge-group 45
!
interface BVI1
description native
ip address 192.168.101.1 255.255.255.0
ip helper-address 10.1.206.10
!
interface BVI15
description WiredData
ip address 10.2.16.1 255.255.255.0
ip nat inside
ip nat enable
ip virtual-reassembly
!
interface BVI20
description Servers
ip address 10.2.17.1 255.255.255.0
ip nat inside
ip nat enable
ip virtual-reassembly
!
interface BVI25
description WiredVoice
ip address 10.2.116.1 255.255.255.0
ip nat inside
ip nat enable
ip virtual-reassembly
!
interface BVI35
description WLANData
ip address 10.2.217.1 255.255.255.0
ip nat inside
ip nat enable
ip virtual-reassembly
!
interface BVI45
description WLANVoice
ip address 10.2.117.1 255.255.255.0
ip nat inside
ip nat enable
ip virtual-reassembly
!
ip route 0.0.0.0 0.0.0.0 24.11.70.245
ip route 10.1.0.0 255.255.0.0 10.2.5.1
ip route 10.1.2.0 255.255.255.0 10.2.5.1
!
!
ip http server
ip http secure-server
ip http timeout-policy idle 60 life 86400 requests 10000
ip nat pool iCOMM 24.11.70.173 24.11.70.174 prefix-length 30
ip nat inside source list 120 interface Satellite1/0 overload
!
access-list 120 permit ip 10.2.16.0 0.0.0.255 any
access-list 120 permit ip 10.2.217.0 0.0.0.255 any
access-list 120 permit ip 10.2.116.0 0.0.0.255 any
access-list 120 permit ip 24.11.70.168 0.0.0.7 any
access-list 120 permit ip 10.2.117.0 0.0.0.255 any
!
!
!
!
!
!
control-plane
!
bridge 1 protocol ieee
bridge 1 route ip
bridge 15 protocol ieee
bridge 15 route ip
bridge 20 protocol ieee
bridge 20 route ip
bridge 25 protocol ieee
bridge 25 route ip
bridge 35 protocol ieee
bridge 35 route ip
bridge 45 protocol ieee
bridge 45 route ip
!
!
voice-port 0/1/0
!
voice-port 0/1/1
!
voice-port 0/2/0
!
voice-port 0/2/1
!
voice-port 0/2/2
!
voice-port 0/2/3
!
!
!
!
dspfarm profile 1 transcode
codec g711ulaw
codec g711alaw
codec g729ar8
codec g729abr8
codec gsmfr
associate application SCCP
maximum sessions 12
!
!
dial-peer voice 1 pots
translation-profile incoming SAT
preference 7
incoming called-number .
direct-inward-dial
!
dial-peer voice 9 voip
destination-pattern .T
voice-class codec 1
session protocol sipv2
session target ipv4:198.102.22.150
dtmf-relay rtp-nte
no vad
!
dial-peer voice 10 voip
session protocol sipv2
incoming called-number .
dtmf-relay rtp-nte
no vad
!
!
sip-ua
retry options 0
registrar ipv4:198.102.22.150 expires 3600
!
!
!
telephony-service
load 7920 cmterm_7920.4.0-03-01.bin
load 7970 term70.default.loads
max-ephones 55
max-dn 55
ip source-address 10.2.116.1 port 2000
auto assign 1 to 45
auto assign 3 to 60 type 7970
auto assign 2 to 4
calling-number initiator
system message Cisco IMICS
sdspfarm transcode sessions 128
time-zone 5
voicemail 6248
mwi reg-e164
mwi relay
max-conferences 12 gain -6
call-forward pattern .T
web admin system name admin password admin
transfer-system full-consult
secondary-dialtone 9
create cnf-files version-stamp Jan 01 2002 00:00:00
!
!
ephone-dn 1 dual-line
number 6175559034
!
!
ephone-dn 2 dual-line
number 6175559056
!
!
ephone-dn 3 dual-line
number 6175553923
description 6175553923
call-forward busy 6248
call-forward noan 6248 timeout 18
!
!
ephone-dn 4 dual-line
number 6175553937
description 6175553937
call-forward busy 6248
call-forward noan 6248 timeout 18
!
!
ephone-dn 51
number 5101
call-forward busy 6248
call-forward noan 6248 timeout 18
!
!
ephone-dn 52
number 5102
call-forward busy 6248
call-forward noan 6248 timeout 18
!
!
ephone-dn 53
number 5103
call-forward busy 6248
call-forward noan 6248 timeout 18
!
!
ephone-dn 54
number 5104
call-forward busy 6248
call-forward noan 6248 timeout 18
!
!
ephone 1
device-security-mode none
mac-address 0016.46E0.7C53
type 7970
button 1:1
!
!
!
ephone 2
device-security-mode none
mac-address 001A.2F26.5662
type 7970
button 1:2
!
!
!
ephone 3
device-security-mode none
mac-address 0013.C3EF.12C8
type 7970
button 1:3
!
!
!
ephone 4
device-security-mode none
mac-address 0014.69E2.747D
type 7970
button 1:4
!
!
!
ephone 5
device-security-mode none
mac-address 0019.302F.3042
type 7920
button 1:51
!
!
!
ephone 6
device-security-mode none
mac-address 0019.302F.3043
type 7920
button 1:52
!
!
!
ephone 7
device-security-mode none
mac-address 0019.302F.303B
type 7920
button 1:53
!
!
!
ephone 8
device-security-mode none
mac-address 0019.302F.303E
type 7920
button 1:54
!
!
!
ephone 9
device-security-mode none
mac-address 001A.2F63.D882
type 7970
button 1:3
!
!
!
ephone 10
device-security-mode none
mac-address 0019.302F.3047
type 7920
button 1:2
!
!
!
ephone 11
device-security-mode none
mac-address 0019.302F.303C
type 7920
button 1:4
!
!
!
ephone 12
device-security-mode none
mac-address 0019.302F.3046
type 7920
button 1:1
!
!
!
ephone 13
device-security-mode none
mac-address 0019.302F.303F
type 7920
button 1:3
!
!
!
line con 0
login local
stopbits 1
line aux 0
stopbits 1
line 130
no activation-character
no exec
transport preferred none
transport input all
transport output pad telnet rlogin lapb-ta mop udptn v120 ssh
line 194
no activation-character
no exec
transport preferred none
transport input all
transport output pad telnet rlogin lapb-ta mop udptn v120 ssh
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
privilege level 15
login
transport input all
transport output all
line vty 5 10
privilege level 15
login local
transport input all
line vty 11 15
privilege level 15
login local
transport input telnet ssh
!
scheduler allocate 20000 1000
!
webvpn context Default_context
ssl authenticate verify all
!
no inservice
!
!
end
09-06-2010 07:58 AM
If the call connects, unlikely is codec issue.
Do you have a firewall in between CME and SIP SP ?
09-06-2010 08:02 AM
Paolo, thanks for your response. Not sure what you are calling "connects" but the call setup is initiated and the phone rings but the talk path is never cut through. There is no firewall.
09-06-2010 08:08 AM
If they can hear you, but you not them, it's likely a firewall somewhere.
The phone shows when are connected as it changes status.
When connected, press ? twice and note counters status, lost pkts etc.
G.729 does not require transcoding because the phones do it.
Take "debug ccsip messages" with "term mon",
09-07-2010 07:51 AM
I'll get a capture of the debug but.... this is not a case of one-way audio or even a case of no audio. The call drops when the called phone picks up (this also happens when the calls forwards to voicemail). So pressing ? twice does nothing.
09-08-2010 07:23 AM
Debugs will show what is specifically occurring and what codecs are offered from each side. The call to VM probably drops because g729 is negotiated and VM may only be g711.
Also, if you intend to invoke a transcoder, you need to make sure you match dial-peers that have a codec explicitly specified. Don't use voice-class codec. If your VM is downstream of dial-peer 9, and that only supports g711, you should configure 'codec g711ulaw' under the peer and remove the voice-class codec. If the transcoder is functioning fine, it will then be invoked for calls that traverse this gateway.
09-08-2010 06:53 PM
Below is the debug output. The error I get is Q.850 disconnect cause code=47 which means "resource unavailable, unspecified".
CME#debug ccsip all
This may severely impact system performance. Continue? [confirm]
All SIP Call tracing is enabled
CME#debug voip ccapi inout
voip ccapi inout debugging is on
*Aug 30 18:03:55.067: //70/C2E835E78047/CCAPI/cc_handle_inter_digit_timer:
Generate inter-digit timeout CC_EV_CALL_DIGIT_END event
*Aug 30 18:03:55.067: //70/xxxxxxxxxxxx/CCAPI/ccCallReportDigits:
(callID=0x46, digit_event=0x0, enable=FALSE, consume=FALSE)
*Aug 30 18:03:55.067: //70/C2E835E78047/CCAPI/ccCallReportDigits:
Enabled=TRUE, Call Id=70
*Aug 30 18:03:55.067: //70/xxxxxxxxxxxx/CCAPI/cc_api_call_report_digits_done:
(vdbPtr=0x70C04A4C, callID=0x46, disp=0, digit_event=0x0, enable=FALSE, consume=FALSE)
*Aug 30 18:03:55.067: //70/C2E835E78047/CCAPI/cc_api_call_report_digits_done:
Enabled=TRUE, Disposition=0x0, Interface=0x70C04A4C, Call Id=70
*Aug 30 18:03:55.067: //70/C2E835E78047/CCAPI/cc_api_call_report_digits_done:
Call Entry(Initial Digit Timeout=10000(ms), Inter Digit Timeout=10000(ms))
*Aug 30 18:03:55.067: //70/C2E835E78047/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
*Aug 30 18:03:55.067: //70/C2E835E78047/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=9, Params=0xC20DCB7C, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
*Aug 30 18:03:55.067: //70/C2E835E78047/CCAPI/ccCheckClipClir:
In: Calling Number=6175559056(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Aug 30 18:03:55.067: //70/C2E835E78047/CCAPI/ccCheckClipClir:
Out: Calling Number=6175559056(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Aug 30 18:03:55.067: //70/C2E835E78047/CCAPI/ccCallSetupRequest:
Destination Pattern=.T, Called Number=5085554300, Digit Strip=FALSE
*Aug 30 18:03:55.067: //70/C2E835E78047/CCAPI/ccCallSetupRequest:
Calling Number=6175559056(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=5085554300(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=
Account Number=, Final Destination Flag=FALSE,
Guid=C2E835E7-B397-11DF-8047-C5F018D5B587, Outgoing Dial-peer=9
*Aug 30 18:03:55.067: //70/C2E835E78047/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=
----- ccCallInfo IE subfields -----
cisco-ani=6175559056
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=5085554300
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=0 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0
*Aug 30 18:03:55.067: //70/C2E835E78047/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x704697AC, Interface Type=3, Destination=, Mode=0x0,
Call Params(Calling Number=6175559056,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=5085554300(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=RegularLine, FinalDestinationFlag=FALSE, Outgoing Dial-peer=9, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
*Aug 30 18:03:55.067: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Aug 30 18:03:55.067: :cc_get_feature_vsa malloc success
*Aug 30 18:03:55.067: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Aug 30 18:03:55.067: cc_get_feature_vsa count is 2
*Aug 30 18:03:55.067: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Aug 30 18:03:55.067: :FEATURE_VSA attributes are: feature_name:0,fearture_time:3228214376,feature_id:23
*Aug 30 18:03:55.067: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x670BBD5C) with key=[58] to table
*Aug 30 18:03:55.067: //71/000000000000/SIP/State/sipSPIChangeState: 0x670BBD5C : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
*Aug 30 18:03:55.067: //71/000000000000/SIP/Info/ccsip_call_setup_request: This is a TDM-IP call: callID= 71, peer_callID = 70
*Aug 30 18:03:55.067: //71/C2E835E78047/SIP/Info/sipSPIGetOutboundHostAndDestHost: CCSIP: target_host : 198.102.22.150 target_port : 5060
*Aug 30 18:03:55.067: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_SETUP
*Aug 30 18:03:55.067: //71/C2E835E78047/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1
*Aug 30 18:03:55.067: //71/C2E835E78047/CCAPI/ccCallSetContext:
Context=0xC20DCB2C
*Aug 30 18:03:55.067: //70/C2E835E78047/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=9
*Aug 30 18:03:55.067: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 2
*Aug 30 18:03:55.067: //71/C2E835E78047/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 47 to table
*Aug 30 18:03:55.067: //71/C2E835E78047/SIP/Info/sipSPIGetCallConfig: preferred_codec set[0] type :No Codec bytes: 0
*Aug 30 18:03:55.067: //71/C2E835E78047/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
*Aug 30 18:03:55.067: //71/C2E835E78047/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1
*Aug 30 18:03:55.067: //71/C2E835E78047/SIP/Info/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host
*Aug 30 18:03:55.067: //71/C2E835E78047/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 24.11.70.246
*Aug 30 18:03:55.067: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 18492 for stream 1
*Aug 30 18:03:55.067: //71/C2E835E78047/SIP/Media/sipSPIAddSDPMediaPayload: Preferred method of dtmf relay is: 6, with payload: 101
*Aug 30 18:03:55.071: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729r8 codecbytes :20, ptime: 20
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Info/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Info/sipSPIOutgoingCallSDP: Creating recv-only stream for outbound call
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Media/sipSPIProcessRtpSessions: sipSPIProcessRtpSessions
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Media/sipSPIProcessRtpSessions: No active streams.
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Info/sipSPIValidateGtd: Signal Forward disabled
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Info/sipSPIAddMLPPServicesInfo: No MLP Info available on incoming leg
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Info/act_idle_continue_call_setup:
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Info/sipSPIUaddCcbToUACTable: ****Adding to UAC table.
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x670BBD5C key=C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Info/sipSPIUsetBillingProfile: sipCallId for billing records = C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
*Aug 30 18:03:55.071: //71/C2E835E78047/CCAPI/cc_api_call_proceeding:
Interface=0x704697AC, Progress Indication=NULL(0)
*Aug 30 18:03:55.071: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 198.102.22.150,Port 5060, Transport 1, SentBy Port 5060
*Aug 30 18:03:55.071: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone pdt to SIP default timezone = GMT
*Aug 30 18:03:55.071: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIgetRegistrarHost: registrar host retrieved
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Info/sipSPISendInvite: Associated container=0xC2078824 to Invite
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Transport/sipSPITransportSendMessage: msg=0x7076C7D4, addr=198.102.22.150, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x61480394
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x7076C7D4
*Aug 30 18:03:55.071: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x7076C7D4, addr=198.102.22.150, port=5060, connId=1 for UDP
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Info/sentInviteRequest: Sent Invite in state STATE_IDLE
*Aug 30 18:03:55.071: //-1/xxxxxxxxxxxx/SIP/Info/sentInviteRequest: Transaction active. Facilities will be queued.
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/State/sipSPIChangeState: 0x670BBD5C : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_SENT_INVITE, SUBSTATE_NONE)
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Media/sipSPIProcessRtpSessions: sipSPIProcessRtpSessions
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 71) to the VOIP RTP library
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 24.11.70.246
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
laddr = 24.11.70.246, lport = 18492, raddr = 0.0.0.0, rport=0, do_rtcp=FALSE
src_callid = 71, dest_callid = -1, stream type = voice+dtmf, stream direction = RECVONLY
media_ip_addr = 0.0.0.0
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one
*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/State/sipSPIChangeStreamState: Stream (callid = 71) State changed from (STREAM_ADDING) to (STREAM_ACTIVE)
*Aug 30 18:03:55.071: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:5085554300@198.102.22.150:5060 SIP/2.0
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E
Remote-Party-ID: <6175559056>;party=calling;screen=no;privacy=off6175559056>
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>5085554300>
Date: Mon, 30 Aug 2010 18:03:55 GMT
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
Supported: 100rel,timer,resource-priority,replaces
Min-SE: 1800
Cisco-Guid: 3269998055-3013022175-2152187376-416658823
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: 1283191435
Contact: <6175559056>6175559056>
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 276
v=0
o=CiscoSystemsSIP-GW-UserAgent 5684 1861 IN IP4 24.11.70.246
s=SIP Call
c=IN IP4 24.11.70.246
t=0 0
m=audio 18492 RTP/AVP 18 101
c=IN IP4 24.11.70.246
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
*Aug 30 18:03:55.571: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone pdt to SIP default timezone = GMT
*Aug 30 18:03:55.571: //71/C2E835E78047/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off
*Aug 30 18:03:55.571: //71/C2E835E78047/SIP/Info/sipSPISendInvite: Associated container=0xC2078824 to Invite
*Aug 30 18:03:55.571: //71/C2E835E78047/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
*Aug 30 18:03:55.571: //71/C2E835E78047/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
*Aug 30 18:03:55.571: //71/C2E835E78047/SIP/Transport/sipSPITransportSendMessage: msg=0x67253FA4, addr=198.102.22.150, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x00000000
*Aug 30 18:03:55.571: //71/C2E835E78047/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Aug 30 18:03:55.571: //71/C2E835E78047/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Aug 30 18:03:55.571: //71/C2E835E78047/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x67253FA4
*Aug 30 18:03:55.571: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x67253FA4, addr=198.102.22.150, port=5060, connId=1 for UDP
*Aug 30 18:03:55.571: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:5085554300@198.102.22.150:5060 SIP/2.0
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E
Remote-Party-ID: <6175559056>;party=calling;screen=no;privacy=off6175559056>
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>5085554300>
Date: Mon, 30 Aug 2010 18:03:55 GMT
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
Supported: 100rel,timer,resource-priority,replaces
Min-SE: 1800
Cisco-Guid: 3269998055-3013022175-2152187376-416658823
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: 1283191435
Contact: <6175559056>6175559056>
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 276
v=0
o=CiscoSystemsSIP-GW-UserAgent 5684 1861 IN IP4 24.11.70.246
s=SIP Call
c=IN IP4 24.11.70.246
t=0 0
m=audio 18492 RTP/AVP 18 101
c=IN IP4 24.11.70.246
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
*Aug 30 18:03:56.571: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone pdt to SIP default timezone = GMT
*Aug 30 18:03:56.571: //71/C2E835E78047/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off
*Aug 30 18:03:56.571: //71/C2E835E78047/SIP/Info/sipSPISendInvite: Associated container=0xC2078824 to Invite
*Aug 30 18:03:56.571: //71/C2E835E78047/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
*Aug 30 18:03:56.571: //71/C2E835E78047/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
*Aug 30 18:03:56.571: //71/C2E835E78047/SIP/Transport/sipSPITransportSendMessage: msg=0x67253FA4, addr=198.102.22.150, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x00000000
*Aug 30 18:03:56.571: //71/C2E835E78047/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Aug 30 18:03:56.571: //71/C2E835E78047/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Aug 30 18:03:56.571: //71/C2E835E78047/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x67253FA4
*Aug 30 18:03:56.571: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x67253FA4, addr=198.102.22.150, port=5060, connId=1 for UDP
*Aug 30 18:03:56.571: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:5085554300@198.102.22.150:5060 SIP/2.0
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E
Remote-Party-ID: <6175559056>;party=calling;screen=no;privacy=off6175559056>
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>5085554300>
Date: Mon, 30 Aug 2010 18:03:56 GMT
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
Supported: 100rel,timer,resource-priority,replaces
Min-SE: 1800
Cisco-Guid: 3269998055-3013022175-2152187376-416658823
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: 1283191436
Contact: <6175559056>6175559056>
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 276
v=0
o=CiscoSystemsSIP-GW-UserAgent 5684 1861 IN IP4 24.11.70.246
s=SIP Call
c=IN IP4 24.11.70.246
t=0 0
m=audio 18492 RTP/AVP 18 101
c=IN IP4 24.11.70.246
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 100 Trying
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>;tag=961666c6-13c4-4c7c01c2-b3f42025-9345085554300>
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
CSeq: 101 INVITE
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E
Timestamp: 1283191435
Contact: <5085554300>5085554300>
Content-Length: 0
*Aug 30 18:03:57.199: //71/C2E835E78047/SIP/State/sipSPIChangeState: 0x670BBD5C : State change from (STATE_SENT_INVITE, SUBSTATE_NONE) to (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING)
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 100 Trying
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>;tag=961666c6-13c4-4c7c01c2-b3f42025-9345085554300>
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
CSeq: 101 INVITE
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E
Timestamp: 1283191435
Contact: <5085554300>5085554300>
Content-Length: 0
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Aug 30 18:03:57.199: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 100 Trying
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>;tag=961666c6-13c4-4c7c01c2-b3f42025-9345085554300>
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
CSeq: 101 INVITE
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E
Timestamp: 1283191435
Contact: <5085554300>5085554300>
Content-Length: 0
*Aug 30 18:03:58.695: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Aug 30 18:03:58.695: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Aug 30 18:03:58.695: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Aug 30 18:03:58.695: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Aug 30 18:03:58.699: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 180 Ringing
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>;tag=961666c6-13c4-4c7c01c2-b3f42025-9345085554300>
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
CSeq: 101 INVITE
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E
Contact: <5085554300>5085554300>
Content-Length: 0
*Aug 30 18:03:58.699: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
*Aug 30 18:03:58.699: //71/C2E835E78047/SIP/Info/sipSPIGetContentSDP: No SDP found in inbound container
*Aug 30 18:03:58.699: //71/C2E835E78047/SIP/Error/sipSPIProcessCallInfoHeader: Call-Info header with for Unsolicited Notify Absent,Disabling Unsolicited Notifies
*Aug 30 18:03:58.699: //71/C2E835E78047/SIP/Info/ccsip_api_call_alert: SDP Body either absent or ignored in 180 RINGING:- will wait for 200 OK to do negotiation.
*Aug 30 18:03:58.699: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateRawMsg: No GTD passed.
*Aug 30 18:03:58.699: //71/C2E835E78047/CCAPI/cc_api_call_alert:
Interface=0x704697AC, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
*Aug 30 18:03:58.699: //71/C2E835E78047/CCAPI/cc_api_call_alert:
Call Entry(Retry Count=0, Responsed=TRUE)
*Aug 30 18:03:58.699: //71/C2E835E78047/SIP/Info/HandleSIP1xxRinging: ccsip_api_call_alert returned: SIP_SUCCESS
*Aug 30 18:03:58.699: //71/C2E835E78047/SIP/State/sipSPIChangeState: 0x670BBD5C : State change from (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) to (STATE_RECD_PROCEEDING, SUBSTATE_NONE)
*Aug 30 18:03:58.699: //71/C2E835E78047/SIP/Info/HandleSIP1xxRinging: Transaction Complete. Lock on Facilities released.
*Aug 30 18:03:58.699: //70/C2E835E78047/CCAPI/ccCallAlert:
Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
*Aug 30 18:03:58.699: //70/C2E835E78047/CCAPI/ccCallAlert:
Call Entry(Responsed=TRUE, AlertSent=TRUE)
*Aug 30 18:03:58.699: //71/C2E835E78047/CCAPI/cc_api_get_ccm_detected:
CallInfo(ccm detected=FALSE)
*Aug 30 18:03:58.699: //70/C2E835E78047/CCAPI/ccCallFeature:
Feature Type=25, Call Id=70
*Aug 30 18:04:08.687: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Aug 30 18:04:08.687: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Aug 30 18:04:08.687: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Aug 30 18:04:08.687: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Aug 30 18:04:08.687: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>;tag=961666c6-13c4-4c7c01c2-b3f42025-9345085554300>
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
CSeq: 101 INVITE
Session-Expires: 1800;refresher=uac
Supported: timer
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E
Contact: <5085554300>5085554300>
Content-Type: application/SDP
Content-Length: 220
v=0
o=CiscoSystemsSIP-GW-UserAgent 6149 1201 IN IP4 198.102.22.157
s=SIP Call
c=IN IP4 198.102.22.157
t=0 0
m=audio 18980 RTP/AVP 18
c=IN IP4 198.102.22.157
a=fmtp:18 annexb=no
a=ptime:20
a=rtpmap:18 G729/8000
*Aug 30 18:04:08.687: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Info/sipSPIhandle200OKInvite: Transaction active. Facilities will be queued.
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Info/sipSPIhandle200OKInvite: *** This ccb is the parent
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Error/sipSPIProcessCallInfoHeader: Call-Info header with for Unsolicited Notify Absent,Disabling Unsolicited Notifies
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Info/sipSPIUACSessionTimer:
Session-Expires value: 1800 refresher: 1
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Info/sipSPIUACSessionTimer:
UAC refresher Timer interval is 900000
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Info/sipSPICompareRespMediaInfo: No Comparsion needed as 18x response SDP is either absent or ignored
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Media/sipSPISelectCodecVersion: g729r8 flavor of g729 codec will be used
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Info/sipSPIDoAudioNegotiation: Codec (g729r8) Negotiation Successful on Static Payload for m-line 1
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20
*Aug 30 18:04:08.687: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g729r8 ptime :20, codecbytes: 20
*Aug 30 18:04:08.687: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729r8 codecbytes :20, ptime: 20
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 20 for codec g729r8
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Info/sipSPIDoDTMFRelayNegotiation: Requested DTMF-RELAY option(s) not found in Preferred DTMF-RELAY option list!
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Info/sipSPIStreamTypeAndDtmfRelay: DTMF Relay mode: Inband Voice
*Aug 30 18:04:08.687: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1
payload_type=18, codec_bytes=20, codec=g729r8, dtmf_relay=inband-voice
stream_type=voice-only (0), dest_ip_address=198.102.22.157, dest_port=18980
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING)
*Aug 30 18:04:08.687: //71/C2E835E78047/SIP/Media/sipSPIUpdCallWithSdpInfo:
Preferred Codec : g729r8, bytes :20
Preferred DTMF relay : rtp-nte
Preferred NTE payload : 101
Early Media : No
Delayed Media : No
Bridge Done : No
New Media : No
DSP DNLD Reqd : No
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 24.11.70.246
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Media/sipSPIUpdCallWithSdpInfo:
Stream type : voice-only
Media line : 1
State : STREAM_ADDING (2)
Callid : 71
Negotiated Codec : g729r8, bytes :20
Negotiated DTMF relay : inband-voice
Negotiated NTE payload : 0
Negotiated CN payload : 0
Media Srce Addr/Port : 24.11.70.246:18492
Media Dest Addr/Port : 198.102.22.157:18980
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sipSPIhandle200OKInvite: ccsip_api_call_connect_media returned: SIP_SUCCESS
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/State/sipSPIChangeState: 0x670BBD5C : State change from (STATE_RECD_PROCEEDING, SUBSTATE_NONE) to (STATE_RECD_PROCEEDING, SUBSTATE_NONE)
*Aug 30 18:04:08.691: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateRawMsg: No GTD passed.
*Aug 30 18:04:08.691: //71/C2E835E78047/CCAPI/cc_api_call_connected:
Interface=0x704697AC, Data Bitmask=0x0, Progress Indication=NULL(0),
Connection Handle=0
*Aug 30 18:04:08.691: //71/C2E835E78047/CCAPI/cc_api_call_connected:
Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sipSPIOptionsPing: Session Timer negotiated, not doing Options Ping
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sipSPIhandle200OKInvite: ccsip_api_call_connected returned: SIP_SUCCESS
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Transport/sipSPISendAck: Sending ACK to the transport layer
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Transport/sipSPITransportSendMessage: msg=0x6742FFAC, addr=198.102.22.150, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x614817C4
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x6742FFAC
*Aug 30 18:04:08.691: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x6742FFAC, addr=198.102.22.150, port=5060, connId=1 for UDP
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/State/sipSPIChangeState: 0x670BBD5C : State change from (STATE_RECD_PROCEEDING, SUBSTATE_NONE) to (STATE_ACTIVE, SUBSTATE_NONE)
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x670BBD5C
State of The Call : STATE_ACTIVE
TCP Sockets Used : NO
Calling Number : 6175559056
Called Number : 5085554300
Source IP Address (Sig ): 24.11.70.246
Destn SIP Req Addr:Port : 198.102.22.150:5060
Destn SIP Resp Addr:Port : 198.102.22.150:5060
Destination Name : 198.102.22.150
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Call/sipSPIMediaCallInfo:
Number of Media Streams: 1
Media Stream : 1
Negotiated Codec : g729r8
Negotiated Codec Bytes : 20
Negotiated Dtmf-relay : 0
Dtmf-relay Payload : 0
Source IP Address (Media): 24.11.70.246
Source IP Port (Media): 18492
Destn IP Address (Media): 198.102.22.157
Destn IP Port (Media): 18980
Orig Destn IP Address:Port (Media): 0.0.0.0:0
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sipSPICallActive: Transaction Complete. Lock on Facilities released.
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
*Aug 30 18:04:08.691: //70/C2E835E78047/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Null,
Tone Direction=Network, Params=0x0, Call Id=70
*Aug 30 18:04:08.691: //70/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:
(confID=0xC0BC539C, callID1=0x46, callID2=0x47, tag=0x0)
*Aug 30 18:04:08.691: //70/C2E835E78047/CCAPI/ccConferenceCreate:
Conference Id=0xC0BC539C, Call Id1=70, Call Id2=71, Tag=0x0
*Aug 30 18:04:08.691: //70/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0x8, Source Interface=0x70C04A4C, Source Call Id=70,
Destination Call Id=71, Disposition=0x0, Tag=0xFFFFFFFF
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/ccsip_bridge: confID = 8, srcCallID = 71, dstCallID = 70
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: -1/-1, new src/dest ccCallids: 71/70
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=71, new streamcallid=71
*Aug 30 18:04:08.691: //71/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:
*Aug 30 18:04:08.691: cc_api_get_xcode_stream : 4368
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Media/sipSPIProcessRtpSessions: sipSPIProcessRtpSessions
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice-only (callid 71) to the VOIP RTP library
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 24.11.70.246
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
laddr = 24.11.70.246, lport = 18492, raddr = 198.102.22.157, rport=18980, do_rtcp=TRUE
src_callid = 71, dest_callid = 70, stream type = voice-only, stream direction = SENDRECV
media_ip_addr = 198.102.22.157
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Media/sipSPIUpdateRtcpSession: RTP session already created - update
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sipSPICreateAndStartRtpTimer:
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled.
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Media/sipSPIGetNewLocalMediaDirection:
New Remote Media Direction = SENDRECV
Present Local Media Direction = SENDRECV
New Local Media Direction = SENDRECV
retVal = 0
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/State/sipSPIChangeStreamState: Stream (callid = 71) State changed from (STREAM_ADDING) to (STREAM_ACTIVE)
*Aug 30 18:04:08.691: //71/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0x8, Source Interface=0x704697AC, Source Call Id=71,
Destination Call Id=70, Disposition=0x0, Tag=0x0
*Aug 30 18:04:08.691: //70/C2E835E78047/CCAPI/cc_generic_bridge_done:
Conference Id=0x8, Source Interface=0x704697AC, Source Call Id=71,
Destination Call Id=70, Disposition=0x0, Tag=0x0
*Aug 30 18:04:08.691: //70/C2E835E78047/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0x8, Destination Call Id=71)
*Aug 30 18:04:08.691: //71/C2E835E78047/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0x8, Destination Call Id=70)
*Aug 30 18:04:08.691: //70/C2E835E78047/CCAPI/cc_api_caps_ind:
Destination Interface=0x704697AC, Destination Call Id=71, Source Call Id=70,
Caps(Codec=0x1, Fax Rate=0x1, Vad=0x1,
Modem=0x0, Codec Bytes=20, Signal Type=3)
*Aug 30 18:04:08.691: //70/C2E835E78047/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=250(ms), Fax Nom=300(ms))
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=71, current_seq_num=0x1190
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=71, current_seq_num=0xF3E
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/ccsip_caps_ind: Load DSP with negotiated codec: g729r8, Bytes=20
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/ccsip_caps_ind: Set forking flag to 0x0
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_INBAND_VOICE_AND_OOB
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sip_set_modem_caps: Disabling Modem Relay...
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/sip_set_modem_caps: nse payload = 0, ptru mode = 0, ptru-codec=0, redundancy=0, xid=0, relay=0, sprt-retry=12, latecncy=200, compres-dir=3, dict=1024, strnlen=32
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Media/sipSPISetStreamInfo: 1 Active Streams
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Media/sipSPISetStreamInfo: Adding stream type (voice-only) from media line 1
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Media/sipSPISetStreamInfo:
caps.stream_count=1,caps.stream[0].stream_type=0x1, caps.stream_list.xmitFunc=
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Media/sipSPISetStreamInfo: voip_rtp_xmit, caps.stream_list.context=
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Media/sipSPISetStreamInfo: 0x705BF360 (gccb)
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/ccsip_caps_ind: ccsip_caps_ind: ccb->pld.flags_ipip = 0x201
*Aug 30 18:04:08.691: //71/C2E835E78047/CCAPI/cc_api_caps_ind:
Destination Interface=0x70C04A4C, Destination Call Id=70, Source Call Id=71,
Caps(Codec=0x4, Fax Rate=0x2, Vad=0x1,
Modem=0x0, Codec Bytes=20, Signal Type=2)
*Aug 30 18:04:08.691: //71/C2E835E78047/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=250(ms), Fax Nom=300(ms))
*Aug 30 18:04:08.691: //71/C2E835E78047/CCAPI/cc_api_caps_ack:
Destination Interface=0x70C04A4C, Destination Call Id=70, Source Call Id=71,
Caps(Codec=g729r8(0x4), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1),
Modem=OFF(0x0), Codec Bytes=20, Signal Type=2, Seq Num Start=3903)
*Aug 30 18:04:08.691: //70/C2E835E78047/CCAPI/cc_api_caps_ack:
Destination Interface=0x704697AC, Destination Call Id=71, Source Call Id=70,
Caps(Codec=g729r8(0x4), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1),
Modem=OFF(0x0), Codec Bytes=20, Signal Type=2, Seq Num Start=3903)
*Aug 30 18:04:08.691: //71/C2E835E78047/SIP/Info/ccsip_caps_ack: Set forking flag to 0x0
*Aug 30 18:04:08.695: //70/C2E835E78047/CCAPI/cc_api_voice_mode_event:
Call Id=70
*Aug 30 18:04:08.695: //70/C2E835E78047/CCAPI/cc_api_voice_mode_event:
Call Entry(Context=0xC20DBDD4)
*Aug 30 18:04:08.695: //70/C2E835E78047/CCAPI/cc_process_notify_bridge_done:
Conference Id=0x8, Call Id1=70, Call Id2=71
*Aug 30 18:04:08.695: //71/C2E835E78047/CCAPI/cc_api_call_disconnected:
Cause Value=47, Interface=0x70C04A4C, Call Id=71
*Aug 30 18:04:08.695: //71/C2E835E78047/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=47, Retry Count=0)
*Aug 30 18:04:08.695: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
ACK sip:5085554300@198.102.22.150:5060 SIP/2.0
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4322F3
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>;tag=961666c6-13c4-4c7c01c2-b3f42025-9345085554300>
Date: Mon, 30 Aug 2010 18:03:56 GMT
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event
Content-Length: 0
*Aug 30 18:04:08.695: //70/C2E835E78047/CCAPI/ccCallConnect:
Progress Indication=NULL(0), Data Bitmask=0x0
*Aug 30 18:04:08.695: //70/C2E835E78047/CCAPI/ccCallConnect:
Call Entry(Connected=TRUE, Responsed=TRUE)
*Aug 30 18:04:08.695: //71/C2E835E78047/CCAPI/cc_api_get_ccm_detected:
CallInfo(ccm detected=FALSE)
*Aug 30 18:04:08.695: //70/C2E835E78047/CCAPI/ccCallFeature:
Feature Type=25, Call Id=70
*Aug 30 18:04:08.699: //70/C2E835E78047/CCAPI/ccConferenceDestroy:
Conference Id=0x8, Tag=0x0
*Aug 30 18:04:08.699: //70/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done:
Conference Id=0x8, Source Interface=0x70C04A4C, Source Call Id=70,
Destination Call Id=71, Disposition=0x0, Tag=0x0
*Aug 30 18:04:08.699: //71/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done:
Conference Id=0x8, Source Interface=0x704697AC, Source Call Id=71,
Destination Call Id=70, Disposition=0x0, Tag=0x0
*Aug 30 18:04:08.699: //70/C2E835E78047/CCAPI/cc_generic_bridge_done:
Conference Id=0x8, Source Interface=0x704697AC, Source Call Id=71,
Destination Call Id=70, Disposition=0x0, Tag=0x0
*Aug 30 18:04:08.699: //70/C2E835E78047/CCAPI/ccCallDisconnect:
Cause Value=47, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
*Aug 30 18:04:08.699: //70/C2E835E78047/CCAPI/ccCallDisconnect:
Cause Value=47, Call Entry(Responsed=TRUE, Cause Value=47)
*Aug 30 18:04:08.699: //70/C2E835E78047/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
*Aug 30 18:04:08.699: //71/C2E835E78047/CCAPI/ccCallDisconnect:
Cause Value=47, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=47)
*Aug 30 18:04:08.699: //71/C2E835E78047/CCAPI/ccCallDisconnect:
Cause Value=47, Call Entry(Responsed=TRUE, Cause Value=47)
*Aug 30 18:04:08.699: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
*Aug 30 18:04:08.699: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 7
*Aug 30 18:04:08.699: //71/C2E835E78047/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
*Aug 30 18:04:08.699: //71/C2E835E78047/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
*Aug 30 18:04:08.699: //71/C2E835E78047/SIP/Info/sipSPISendBye: Associated container=0xC207D75C to Bye
*Aug 30 18:04:08.699: //71/C2E835E78047/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer
*Aug 30 18:04:08.699: //71/C2E835E78047/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
*Aug 30 18:04:08.699: //71/C2E835E78047/SIP/Transport/sipSPITransportSendMessage: msg=0xC09DE544, addr=198.102.22.150, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x61481154
*Aug 30 18:04:08.699: //71/C2E835E78047/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Aug 30 18:04:08.699: //71/C2E835E78047/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Aug 30 18:04:08.699: //71/C2E835E78047/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0xC09DE544
*Aug 30 18:04:08.699: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0xC09DE544, addr=198.102.22.150, port=5060, connId=1 for UDP
*Aug 30 18:04:08.699: //71/C2E835E78047/SIP/Info/sentByeDisconnecting: Sent Bye Request, starting DisconnectTimer
*Aug 30 18:04:08.699: //71/C2E835E78047/SIP/State/sipSPIChangeState: 0x670BBD5C : State change from (STATE_ACTIVE, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)
*Aug 30 18:04:08.699: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
BYE sip:5085554300@198.102.22.150:5060 SIP/2.0
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK441389
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>;tag=961666c6-13c4-4c7c01c2-b3f42025-9345085554300>
Date: Mon, 30 Aug 2010 18:03:56 GMT
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
User-Agent: Cisco-SIPGateway/IOS-12.x
Max-Forwards: 70
Timestamp: 1283191448
CSeq: 102 BYE
Reason: Q.850;cause=47
Content-Length: 0
*Aug 30 18:04:08.699: //70/C2E835E78047/CCAPI/cc_api_call_feature:
Feature Type=6, Interface=0x70C04A4C, Call Id=70
*Aug 30 18:04:08.703: //70/C2E835E78047/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x70C04A4C, Tag=0x0, Call Id=70,
Call Entry(Disconnect Cause=47, Voice Class Cause Code=0, Retry Count=0)
*Aug 30 18:04:08.703: //70/C2E835E78047/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Aug 30 18:04:08.703: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Aug 30 18:04:08.703: :cc_free_feature_vsa freeing C06AA388
*Aug 30 18:04:08.703: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Aug 30 18:04:08.703: vsacount in free is 1
*Aug 30 18:04:09.619: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Aug 30 18:04:09.619: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Aug 30 18:04:09.619: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Aug 30 18:04:09.619: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Aug 30 18:04:09.619: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>;tag=961666c6-13c4-4c7c01c2-b3f42025-9345085554300>
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
CSeq: 101 INVITE
Session-Expires: 1800;refresher=uac
Supported: timer
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E
Contact: <5085554300>5085554300>
Content-Type: application/SDP
Content-Length: 220
v=0
o=CiscoSystemsSIP-GW-UserAgent 6149 1201 IN IP4 198.102.22.157
s=SIP Call
c=IN IP4 198.102.22.157
t=0 0
m=audio 18980 RTP/AVP 18
c=IN IP4 198.102.22.157
a=fmtp:18 annexb=no
a=ptime:20
a=rtpmap:18 G729/8000
*Aug 30 18:04:09.619: //71/C2E835E78047/SIP/Error/sact_disconnecting_new_message_response: Out of Context 2xx response received
*Aug 30 18:04:09.623: //71/C2E835E78047/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
*Aug 30 18:04:09.623: //71/C2E835E78047/SIP/Info/sipSPISendBye: Associated container=0xC207D75C to Bye
*Aug 30 18:04:09.623: //71/C2E835E78047/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer
*Aug 30 18:04:09.623: //71/C2E835E78047/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
*Aug 30 18:04:09.623: //71/C2E835E78047/SIP/Transport/sipSPITransportSendMessage: msg=0xC09DE544, addr=198.102.22.150, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x00000000
*Aug 30 18:04:09.623: //71/C2E835E78047/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Aug 30 18:04:09.623: //71/C2E835E78047/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Aug 30 18:04:09.623: //71/C2E835E78047/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0xC09DE544
*Aug 30 18:04:09.623: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0xC09DE544, addr=198.102.22.150, port=5060, connId=1 for UDP
*Aug 30 18:04:09.623: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
BYE sip:5085554300@198.102.22.150:5060 SIP/2.0
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK441389
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>;tag=961666c6-13c4-4c7c01c2-b3f42025-9345085554300>
Date: Mon, 30 Aug 2010 18:03:56 GMT
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
User-Agent: Cisco-SIPGateway/IOS-12.x
Max-Forwards: 70
Timestamp: 1283191449
CSeq: 102 BYE
Reason: Q.850;cause=47
Content-Length: 0
*Aug 30 18:04:10.103: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Aug 30 18:04:10.103: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Aug 30 18:04:10.103: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Aug 30 18:04:10.103: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Aug 30 18:04:10.103: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>;tag=961666c6-13c4-4c7c01c2-b3f42025-9345085554300>
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
CSeq: 101 INVITE
Session-Expires: 1800;refresher=uac
Supported: timer
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E
Contact: <5085554300>5085554300>
Content-Type: application/SDP
Content-Length: 220
v=0
o=CiscoSystemsSIP-GW-UserAgent 6149 1201 IN IP4 198.102.22.157
s=SIP Call
c=IN IP4 198.102.22.157
t=0 0
m=audio 18980 RTP/AVP 18
c=IN IP4 198.102.22.157
a=fmtp:18 annexb=no
a=ptime:20
a=rtpmap:18 G729/8000
*Aug 30 18:04:10.103: //71/C2E835E78047/SIP/Error/sact_disconnecting_new_message_response: Out of Context 2xx response received
*Aug 30 18:04:10.103: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Aug 30 18:04:10.103: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Aug 30 18:04:10.103: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Aug 30 18:04:10.103: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Aug 30 18:04:10.103: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>;tag=961666c6-13c4-4c7c01c2-b3f42025-9345085554300>
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
CSeq: 102 BYE
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK441389
Content-Length: 0
*Aug 30 18:04:10.103: //71/C2E835E78047/SIP/Info/sipSPIIcpifUpdate: CallState: 4 Playout: 0 DiscTime:556005 ConnTime 555864
*Aug 30 18:04:10.103: //71/C2E835E78047/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x704697AC, Tag=0x0, Call Id=71,
Call Entry(Disconnect Cause=47, Voice Class Cause Code=0, Retry Count=0)
*Aug 30 18:04:10.103: //71/C2E835E78047/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Aug 30 18:04:10.103: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Aug 30 18:04:10.103: :cc_free_feature_vsa freeing C06AA460
*Aug 30 18:04:10.103: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Aug 30 18:04:10.103: vsacount in free is 0
*Aug 30 18:04:10.103: //71/C2E835E78047/SIP/State/sipSPIChangeState: 0x670BBD5C : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE)
*Aug 30 18:04:10.103: //71/C2E835E78047/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x670BBD5C
State of The Call : STATE_DEAD
TCP Sockets Used : NO
Calling Number : 6175559056
Called Number : 5085554300
Source IP Address (Sig ): 24.11.70.246
Destn SIP Req Addr:Port : 198.102.22.150:5060
Destn SIP Resp Addr:Port : 198.102.22.150:5060
Destination Name : 198.102.22.150
*Aug 30 18:04:10.103: //71/C2E835E78047/SIP/Call/sipSPIMediaCallInfo:
Number of Media Streams: 1
Media Stream : 1
Negotiated Codec : g729r8
Negotiated Codec Bytes : 20
Negotiated Dtmf-relay : 0
Dtmf-relay Payload : 0
Source IP Address (Media): 24.11.70.246
Source IP Port (Media): 18492
Destn IP Address (Media): 198.102.22.157
Destn IP Port (Media): 18980
Orig Destn IP Address:Port (Media): 0.0.0.0:0
*Aug 30 18:04:10.103: //71/C2E835E78047/SIP/Call/sipSPICallInfo:
Disconnect Cause (CC) : 47
Disconnect Cause (SIP) : 200
*Aug 30 18:04:10.103: //71/C2E835E78047/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 47
*Aug 30 18:04:10.103: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[58] removed.
*Aug 30 18:04:10.103: //71/C2E835E78047/SIP/Info/sipSPIUdeleteCcbFromUACTable: ****Deleting from UAC table.
*Aug 30 18:04:10.103: //71/C2E835E78047/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x670BBD5C key=C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
*Aug 30 18:04:10.103: //71/C2E835E78047/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
*Aug 30 18:04:10.103: //71/C2E835E78047/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 670BBD5C
*Aug 30 18:04:10.103: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[58]
*Aug 30 18:04:10.999: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Aug 30 18:04:10.999: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Aug 30 18:04:10.999: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Aug 30 18:04:10.999: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Aug 30 18:04:10.999: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK
From: <6175559056>;tag=549C40-173C6175559056>
To: <5085554300>;tag=961666c6-13c4-4c7c01c2-b3f42025-9345085554300>
Call-ID: C9C12499-B39711DF-804CC5F0-18D5B587@24.11.70.246
CSeq: 102 BYE
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK441389
Content-Length: 0
*Aug 30 18:04:10.999: //-1/xxxxxxxxxxxx/SIP/Error/sipSPILocateInviteDialogCCB: Could not find ccb for response
CME#
09-09-2010 06:30 AM
The debugs aren't complete. They are missing the output of the inbound dial-peer match at the start of the call. Try running them again with the following method:
Router(config)# service sequence
Router(config)# service timestamps debug datetime msec
Router(config)# logging buffered 10000000 7
Router(config)# no logging con
Router(config)# no logging mon
Router(config)# voice iec syslog
Router# term len 0
Router# sh logg
Because I can't see what happens on the inbound leg, I don't know what codec we need to be negotiating with your ITSP.
I see the call going out dial-peer 9, but I thought this was a CME system with an inbound call from a SIP trunk to an IP phone? If that's the case, you should be matching a dial-peer in the 20XXX range. Perhaps your translatations or destination-patterns aren't configured right, but I can't help much without seeing what the call looks like as it comes into the box.
10-04-2010 07:13 AM
Steven,
Thanks for the response.
The debug output was from a call that was initiated by a CME phone. The problem is the same either way. Destination phone rings, disco on pickup. I'm going to do more testing today with your suggestions and post the output.
-mike
10-07-2010 01:21 PM
Finally got around to it. Here's the "ccsip all" debug output. Same problem - getting an immediate disconnect when the called party answers.
Calling party - 508-555-4300
Called party (CME phone) - 617-555-9056
=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2010.10.07 15:38:00 =~=~=~=~=~=~=~=~=~=~=~=
sh logg
Syslog logging: enabled (12 messages dropped, 2 messages rate-limited,
0 flushes, 0 overruns, xml disabled, filtering disabled)
No Active Message Discriminator.
No Inactive Message Discriminator.
Console logging: disabled
Monitor logging: disabled
Buffer logging: level debugging, 270 messages logged, xml disabled,
filtering disabled
Logging Exception size (4096 bytes)
Count and timestamp logging messages: disabled
No active filter modules.
Trap logging: level informational, 82 message lines logged
Log Buffer (10000000 bytes):
*Oct 7 19:36:36.131: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Oct 7 19:36:36.131: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Oct 7 19:36:36.131: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Oct 7 19:36:36.131: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:6175559056@24.11.70.246:5060 SIP/2.0
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
To: <6175559056>6175559056>
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
CSeq: 1 INVITE
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3090-77fa36b5-24f9
Max-Forwards: 70
Contact: <5085554300>5085554300>
Content-Type: application/SDP
Content-Length: 220
v=0
o=CiscoSystemsSIP-GW-UserAgent 9599 1444 IN IP4 198.102.22.157
s=SIP Call
c=IN IP4 198.102.22.157
t=0 0
m=audio 17056 RTP/AVP 18
c=IN IP4 198.102.22.157
a=fmtp:18 annexb=no
a=ptime:20
a=rtpmap:18 G729/8000
*Oct 7 19:36:36.131: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Oct 7 19:36:36.131: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x708E70F0) with key=[35] to table
*Oct 7 19:36:36.131: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 198.102.22.150,Port 5060,
Transport 1, SentBy Port 5060
*Oct 7 19:36:36.131: //-1/081A0E098014/SIP/State/sipSPIChangeState: 0x708E70F0 : State change from (STATE_NONE, SUBSTATE_NONE) to
(STATE_IDLE, SUBSTATE_NONE)
*Oct 7 19:36:36.131: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 198.102.22.150,Port 5060,
Transport 1, SentBy Port 5060
*Oct 7 19:36:36.131: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone pdt to SIP default timezone = GMT
*Oct 7 19:36:36.131: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 198.102.22.150,Port 5060,
Transport 1, SentBy Port 5060
*Oct 7 19:36:36.131: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
*Oct 7 19:36:36.135: //-1/081A0E098014/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
*Oct 7 19:36:36.135: //-1/081A0E098014/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x708E70F0
key=76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.1576175559056
*Oct 7 19:36:36.135: //-1/081A0E098014/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id
*Oct 7 19:36:36.135: //-1/081A0E098014/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 6175559056
*Oct 7 19:36:36.135: //-1/081A0E098014/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 5085554300
*Oct 7 19:36:36.135: //-1/081A0E098014/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name MASSACHUSETTS , number 5085554300,
Calling oct3 0x00, oct_3a 0x80, Called number 6175559056
*Oct 7 19:36:36.135: //-1/081A0E098014/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
*Oct 7 19:36:36.135: //-1/081A0E098014/SIP/Info/sipSPIGetCallConfig: Peer tag 10 matched for incoming call
*Oct 7 19:36:36.135: //-1/081A0E098014/SIP/Info/sipSPIGetCallConfig: Not using Voice Class Codec
*Oct 7 19:36:36.135: //-1/081A0E098014/SIP/Info/sipSPIContinueNewMsgInvite: Calling name MASSACHUSETTS , number 5085554300, Calling oct3
0x00, oct_3a 0x80, ext_priv 0x00, Called number 6175559056, oct3 0x00
*Oct 7 19:36:36.135: //-1/081A0E098014/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE,
next_tgrp NONE
*Oct 7 19:36:36.135: //-1/081A0E098014/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Error/sipSPIProcessCallInfoHeader: Call-Info header with for Unsolicited Notify Absent,Disabling
Unsolicited Notifies
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Media/sipSPISelectCodecVersion: g729r8 flavor of g729 codec will be used
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIDoAudioNegotiation: Codec (g729r8) Negotiation Successful on Static Payload for
m-line 1
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20
*Oct 7 19:36:36.135: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g729r8 ptime :20, codecbytes: 20
*Oct 7 19:36:36.135: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729r8 codecbytes :20, ptime: 20
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 20
for codec g729r8
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIDoDTMFRelayNegotiation: Requested DTMF-RELAY option(s) not found in Preferred
DTMF-RELAY option list!
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIStreamTypeAndDtmfRelay: DTMF Relay mode: Inband Voice
*Oct 7 19:36:36.135: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction
attributes that can't be handled for m-line:1 and num-a-lines:0
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1
payload_type=18, codec_bytes=20, codec=g729r8, dtmf_relay=inband-voice
stream_type=voice-only (0), dest_ip_address=198.102.22.157, dest_port=17056
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to
(STREAM_ADDING)
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Media/sipSPIUpdCallWithSdpInfo:
Preferred Codec : g729r8, bytes :20
Preferred DTMF relay : rtp-nte
Preferred NTE payload : 101
Early Media : No
Delayed Media : No
Bridge Done : No
New Media : No
DSP DNLD Reqd : No
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 24.11.70.246
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 37 peer 0 flags 0x201
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 37, sdp 0x67C24D34 channels 0x708E81B8
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 18 mline 1
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Media/sipSPISelectCodecVersion: g729r8 flavor of g729 codec will be used
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g729r8
*Oct 7 19:36:36.135: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729r8 codecbytes :20, ptime: 20
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done:
stream->negotiated_ptime=20,stream->negotiated_codec_bytes=20, coverted ptime=20 stream->mline_index=1, media_ndx=1
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Error/sipSPI_ipip_copy_sdp_to_channelInfo:
failed to update call entry
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 16 ptype 18 time 20, bytes 20 as channel 0 mline 1 ss 0 198.102.22.157:17056
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPI_ipip_report_media_to_peer:
Report initial call media
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/copy_channels:
callId 37 size 108 ptr 0x67B7BDB4)
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPI_ipip_report_media_to_peer:
CCSIP: Unable to report channel ind
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Media/sipSPIUpdCallWithSdpInfo:
Stream type : voice-only
Media line : 1
State : STREAM_ADDING (2)
Callid : -1
Negotiated Codec : g729r8, bytes :20
Negotiated DTMF relay : inband-voice
Negotiated NTE payload : 0
Negotiated CN payload : 0
Media Srce Addr/Port : 24.11.70.246:0
Media Dest Addr/Port : 198.102.22.157:17056
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIHandleInviteMedia:
Negotiated Codec : g729r8, bytes :20
Preferred Codec : g729r8, bytes :20
Preferred DTMF relay 1 : 6
Preferred DTMF relay 2 : 0
Negotiated DTMF relay : 0
Preferred and Negotiated NTE payloads: 101 0
Preferred and Negotiated NSE payloads: 100 0
Preferred and Negotiated Modem Relay: 0 0
Preferred and Negotiated Modem Relay GwXid: 1 0
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIDoQoSNegotiation: SDP body with media description
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
*Oct 7 19:36:36.135: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 17440 for stream 1
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=17440
*Oct 7 19:36:36.135: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 17440
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records =
76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPI_ipip_store_channel_info: dtmf negotiation done, storing negotiated dtmf = 0,
*Oct 7 19:36:36.135: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateRawMsg: No GTD passed.
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table.
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x708E70F0
key=76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157580B64-128D
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 25 to table
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: msg=0x70C7A99C, addr=198.102.22.150, port=5060,
sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Oct 7 19:36:36.135: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x70C7A99C, addr=198.102.22.150,
port=5060, connId=0 for UDP
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/State/sipSPIChangeState: 0x708E70F0 : State change from (STATE_IDLE, SUBSTATE_NONE) to
(STATE_RECD_INVITE, SUBSTATE_NONE)
*Oct 7 19:36:36.135: //37/081A0E098014/SIP/Info/sipSPIProcessContactInfo: Previous Hop 198.102.22.150:5060
*Oct 7 19:36:36.139: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3090-77fa36b5-24f9
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
To: <6175559056>;tag=580B64-128D6175559056>
Date: Thu, 07 Oct 2010 19:36:36 GMT
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 INVITE
Allow-Events: telephone-event
Content-Length: 0
*Oct 7 19:36:36.139: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDING
*Oct 7 19:36:36.139: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler:
*Oct 7 19:36:36.139: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 146)
*Oct 7 19:36:36.139: //37/081A0E098014/SIP/Info/ccsip_event_handler:
ccsip_event_handler: peer ID 38 chans 0x6718D9F8 event 146 flags 0x40001C 0x601 data 0x6718D9F8
*Oct 7 19:36:36.139: //37/081A0E098014/SIP/Info/ccsip_event_handler:
ccsip_event_handler: CC_EV_H245_SET_MODE: peer ID 38 chans 0x6718D9F8 event 146 flags 0x40001C 0x601 data 0x6718D9F8
*Oct 7 19:36:36.139: //37/081A0E098014/SIP/Info/ccsip_event_handler:
ccsip_event_handler: CC_EV_H245_SET_MODE: peer ID 38 chans 0x6718D9F8 event 146 flags 0x40001C 0x601 data 0x6718D9F8, type = 6
*Oct 7 19:36:36.139: //37/081A0E098014/SIP/Info/ccsip_event_handler:
ccsip_event_handler: !!!!!CC_EV_H245_SET_MODE: not clearing VTSP flag
*Oct 7 19:36:36.139: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED
*Oct 7 19:36:36.139: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 3
*Oct 7 19:36:36.143: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_ALERTING
*Oct 7 19:36:36.143: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 5
*Oct 7 19:36:36.143: //37/081A0E098014/SIP/Transport/sipSPISendInviteResponse: Sending 180 Response to the Transport Layer
*Oct 7 19:36:36.143: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: msg=0x6798482C, addr=198.102.22.150, port=5060,
sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x61480CB8
*Oct 7 19:36:36.143: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Oct 7 19:36:36.143: //37/081A0E098014/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Oct 7 19:36:36.143: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x6798482C, addr=198.102.22.150,
port=5060, connId=0 for UDP
*Oct 7 19:36:36.143: //37/081A0E098014/SIP/Info/sentInviteResponse18x: Sent a 18x Response
*Oct 7 19:36:36.143: //37/081A0E098014/SIP/State/sipSPIChangeState: 0x708E70F0 : State change from (STATE_RECD_INVITE, SUBSTATE_NONE) to
(STATE_SENT_ALERTING, SUBSTATE_NONE)
*Oct 7 19:36:36.143: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3090-77fa36b5-24f9
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
To: <6175559056>;tag=580B64-128D6175559056>
Date: Thu, 07 Oct 2010 19:36:36 GMT
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Contact: <6175559056>6175559056>
Content-Length: 0
*Oct 7 19:36:36.523: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Oct 7 19:36:36.523: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Oct 7 19:36:36.523: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Oct 7 19:36:36.523: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:6175559056@24.11.70.246:5060 SIP/2.0
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
To: <6175559056>6175559056>
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
CSeq: 1 INVITE
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3090-77fa36b5-24f9
Max-Forwards: 70
Contact: <5085554300>5085554300>
Content-Type: application/SDP
Content-Length: 220
v=0
o=CiscoSystemsSIP-GW-UserAgent 9599 1444 IN IP4 198.102.22.157
s=SIP Call
c=IN IP4 198.102.22.157
t=0 0
m=audio 17056 RTP/AVP 18
c=IN IP4 198.102.22.157
a=fmtp:18 annexb=no
a=ptime:20
a=rtpmap:18 G729/8000
*Oct 7 19:36:36.523: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Oct 7 19:36:36.523: //37/081A0E098014/SIP/Info/sipSPIFindCcbUASReqTable: *****CCB found in UAS Request table. ccb=0x708E70F0
*Oct 7 19:36:36.523: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 198.102.22.150,Port 5060,
Transport 1, SentBy Port 5060
*Oct 7 19:36:36.523: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone pdt to SIP default timezone = GMT
*Oct 7 19:36:36.523: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 198.102.22.150,Port 5060,
Transport 1, SentBy Port 5060
*Oct 7 19:36:36.523: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 0.0.0.0,Port 0, Transport 1,
SentBy Port 5060
*Oct 7 19:36:36.523: //37/081A0E098014/SIP/Transport/sipSPISendInviteResponse: Sending 180 Response to the Transport Layer
*Oct 7 19:36:36.523: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: msg=0x67DBD4E4, addr=198.102.22.150, port=5060,
sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
*Oct 7 19:36:36.523: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Oct 7 19:36:36.523: //37/081A0E098014/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Oct 7 19:36:36.523: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x67DBD4E4, addr=198.102.22.150,
port=5060, connId=0 for UDP
*Oct 7 19:36:36.523: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3090-77fa36b5-24f9
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
To: <6175559056>;tag=580B64-128D6175559056>
Date: Thu, 07 Oct 2010 19:36:36 GMT
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Contact: <6175559056>6175559056>
Content-Length: 0
*Oct 7 19:36:37.331: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Oct 7 19:36:37.331: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Oct 7 19:36:37.331: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Oct 7 19:36:37.331: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:6175559056@24.11.70.246:5060 SIP/2.0
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
To: <6175559056>6175559056>
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
CSeq: 1 INVITE
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3090-77fa36b5-24f9
Max-Forwards: 70
Contact: <5085554300>5085554300>
Content-Type: application/SDP
Content-Length: 220
v=0
o=CiscoSystemsSIP-GW-UserAgent 9599 1444 IN IP4 198.102.22.157
s=SIP Call
c=IN IP4 198.102.22.157
t=0 0
m=audio 17056 RTP/AVP 18
c=IN IP4 198.102.22.157
a=fmtp:18 annexb=no
a=ptime:20
a=rtpmap:18 G729/8000
*Oct 7 19:36:37.331: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Oct 7 19:36:37.331: //37/081A0E098014/SIP/Info/sipSPIFindCcbUASReqTable: *****CCB found in UAS Request table. ccb=0x708E70F0
*Oct 7 19:36:37.331: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 198.102.22.150,Port 5060,
Transport 1, SentBy Port 5060
*Oct 7 19:36:37.331: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone pdt to SIP default timezone = GMT
*Oct 7 19:36:37.331: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 198.102.22.150,Port 5060,
Transport 1, SentBy Port 5060
*Oct 7 19:36:37.331: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 0.0.0.0,Port 0, Transport 1,
SentBy Port 5060
*Oct 7 19:36:37.331: //37/081A0E098014/SIP/Transport/sipSPISendInviteResponse: Sending 180 Response to the Transport Layer
*Oct 7 19:36:37.331: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: msg=0x67DBD4E4, addr=198.102.22.150, port=5060,
sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
*Oct 7 19:36:37.331: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Oct 7 19:36:37.331: //37/081A0E098014/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Oct 7 19:36:37.331: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x67DBD4E4, addr=198.102.22.150,
port=5060, connId=0 for UDP
*Oct 7 19:36:37.335: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3090-77fa36b5-24f9
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
To: <6175559056>;tag=580B64-128D6175559056>
Date: Thu, 07 Oct 2010 19:36:37 GMT
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Contact: <6175559056>6175559056>
Content-Length: 0
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/ccsip_bridge: confID = 3, srcCallID = 37, dstCallID = 38
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: -1/-1, new src/dest ccCallids: 37/38
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=-1, new streamcallid=37
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Media/sipSPIProcessRtpSessions: sipSPIProcessRtpSessions
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice-only (callid 37) to the VOIP RTP library
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 24.11.70.246
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
laddr = 24.11.70.246, lport = 17440, raddr = 198.102.22.157, rport=17056, do_rtcp=TRUE
src_callid = 37, dest_callid = 38, stream type = voice-only, stream direction = SENDRECV
media_ip_addr = 198.102.22.157
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Media/sipSPIGetNewLocalMediaDirection:
New Remote Media Direction = SENDRECV
Present Local Media Direction = SENDRECV
New Local Media Direction = SENDRECV
retVal = 0
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/State/sipSPIChangeStreamState: Stream (callid = 37) State changed from (STREAM_ADDING) to
(STREAM_ACTIVE)
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=37, current_seq_num=0x1112
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=37, current_seq_num=0xAB6
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/ccsip_caps_ind: Load DSP with negotiated codec: g729r8, Bytes=20
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/ccsip_caps_ind: Set forking flag to 0x0
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_INBAND_VOICE_AND_OOB
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI
config=0
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/sip_set_modem_caps: Disabling Modem Relay...
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP
Xcap list
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/sip_set_modem_caps: nse payload = 0, ptru mode = 0, ptru-codec=0, redundancy=0, xid=0,
relay=0, sprt-retry=12, latecncy=200, compres-dir=3, dict=1024, strnlen=32
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Media/sipSPISetStreamInfo: 1 Active Streams
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Media/sipSPISetStreamInfo: Adding stream type (voice-only) from media line 1
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Media/sipSPISetStreamInfo:
caps.stream_count=1,caps.stream[0].stream_type=0x1, caps.stream_list.xmitFunc=
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Media/sipSPISetStreamInfo: voip_rtp_xmit, caps.stream_list.context=
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Media/sipSPISetStreamInfo: 0xC0ABD680 (gccb)
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/ccsip_caps_ind: ccsip_caps_ind: ccb->pld.flags_ipip = 0x603
*Oct 7 19:36:40.231: //37/081A0E098014/SIP/Info/ccsip_caps_ack: Set forking flag to 0x0
*Oct 7 19:36:40.235: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_CONNECT
*Oct 7 19:36:40.235: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 6
*Oct 7 19:36:40.235: //37/081A0E098014/SIP/Info/sipSPISendInviteResponse: Associated container=0x69245808 to Invite Response 200
*Oct 7 19:36:40.235: //37/081A0E098014/SIP/Transport/sipSPISendInviteResponse: Sending 200OK Response to the Transport Layer
*Oct 7 19:36:40.235: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: msg=0x67D954CC, addr=198.102.22.150, port=5060,
sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x61480F0C
*Oct 7 19:36:40.235: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Oct 7 19:36:40.235: //37/081A0E098014/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Oct 7 19:36:40.235: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x67D954CC, addr=198.102.22.150,
port=5060, connId=0 for UDP
*Oct 7 19:36:40.235: //37/081A0E098014/SIP/Info/sentInviteResponse200: Sent 200Ok for Invite in state STATE_SENT_ALERTING
*Oct 7 19:36:40.235: //-1/xxxxxxxxxxxx/SIP/Info/sentInviteResponse200: Transaction active. Facilities will be queued.
*Oct 7 19:36:40.235: //37/081A0E098014/SIP/State/sipSPIChangeState: 0x708E70F0 : State change from (STATE_SENT_ALERTING, SUBSTATE_NONE) to
(STATE_SENT_SUCCESS, SUBSTATE_NONE)
*Oct 7 19:36:40.235: //37/081A0E098014/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be
free'd
*Oct 7 19:36:40.235: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3090-77fa36b5-24f9
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
To: <6175559056>;tag=580B64-128D6175559056>
Date: Thu, 07 Oct 2010 19:36:37 GMT
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Contact: <6175559056>6175559056>
Supported: replaces
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 220
v=0
o=CiscoSystemsSIP-GW-UserAgent 2758 6584 IN IP4 24.11.70.246
s=SIP Call
c=IN IP4 24.11.70.246
t=0 0
m=audio 17440 RTP/AVP 18
c=IN IP4 24.11.70.246
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
*Oct 7 19:36:40.235: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
*Oct 7 19:36:40.235: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 7
*Oct 7 19:36:40.235: //37/081A0E098014/SIP/Info/act_sentsucc_disconnect: Received POTS Disconnect - Holding BYE till we receive ACK or runs
out of retx's
*Oct 7 19:36:40.735: //37/081A0E098014/SIP/Info/sipSPISendInviteResponse: Associated container=0x69245808 to Invite Response 200
*Oct 7 19:36:40.735: //37/081A0E098014/SIP/Transport/sipSPISendInviteResponse: Sending 200OK Response to the Transport Layer
*Oct 7 19:36:40.735: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: msg=0xC0A1FE18, addr=198.102.22.150, port=5060,
sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
*Oct 7 19:36:40.735: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Oct 7 19:36:40.735: //37/081A0E098014/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Oct 7 19:36:40.735: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0xC0A1FE18, addr=198.102.22.150,
port=5060, connId=0 for UDP
*Oct 7 19:36:40.735: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3090-77fa36b5-24f9
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
To: <6175559056>;tag=580B64-128D6175559056>
Date: Thu, 07 Oct 2010 19:36:37 GMT
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Contact: <6175559056>6175559056>
Supported: replaces
Reason: Q.850;cause=47
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 220
v=0
o=CiscoSystemsSIP-GW-UserAgent 2758 6584 IN IP4 24.11.70.246
s=SIP Call
c=IN IP4 24.11.70.246
t=0 0
m=audio 17440 RTP/AVP 18
c=IN IP4 24.11.70.246
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
*Oct 7 19:36:41.591: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Oct 7 19:36:41.591: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Oct 7 19:36:41.591: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Oct 7 19:36:41.591: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:6175559056@24.11.70.246:5060 SIP/2.0
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
To: <6175559056>;tag=580B64-128D6175559056>
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
CSeq: 1 ACK
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3096-77fa4c12-2516
Max-Forwards: 70
Contact: <5085554300>5085554300>
Content-Length: 0
*Oct 7 19:36:41.591: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Oct 7 19:36:41.591: //37/081A0E098014/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x708E70F0
*Oct 7 19:36:41.591: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 198.102.22.150,Port 5060,
Transport 1, SentBy Port 5060
*Oct 7 19:36:41.591: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone pdt to SIP default timezone = GMT
*Oct 7 19:36:41.591: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 198.102.22.150,Port 5060,
Transport 1, SentBy Port 5060
*Oct 7 19:36:41.591: //37/081A0E098014/SIP/Info/act_sentsucc_new_message_request: Transaction Complete. Lock on Facilities released.
*Oct 7 19:36:41.591: //37/081A0E098014/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
*Oct 7 19:36:41.591: //37/081A0E098014/SIP/Info/sipSPISendBye: Associated container=0x69245A9C to Bye
*Oct 7 19:36:41.591: //37/081A0E098014/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer
*Oct 7 19:36:41.591: //37/081A0E098014/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is
FALSE
*Oct 7 19:36:41.595: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: msg=0xC0A1FE18, addr=198.102.22.150, port=5060,
sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x61481154
*Oct 7 19:36:41.595: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Oct 7 19:36:41.595: //37/081A0E098014/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Oct 7 19:36:41.595: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for
holder=0x70240240,addr=198.102.22.150
*Oct 7 19:36:41.595: //-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnHolder: Created new holder=0x70240240, addr=198.102.22.150; nailed=FALSE
*Oct 7 19:36:41.595: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostRequestConnection: Posting UDP conn create request for
addr=198.102.22.150, port=5060, context=0x676D969C
*Oct 7 19:36:41.595: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer: Wait timer set for
connection=0xC0535414,addr=198.102.22.150, port=5060
*Oct 7 19:36:41.595: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer:
Wait Conn Timer started for 5000 msec
*Oct 7 19:36:41.595: //-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnInstance: Created new initiated conn=0xC0535414, connid=-1,
addr=198.102.22.150, port=5060, transport=UDP
*Oct 7 19:36:41.595: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x708E70F0 with connection=0xC0535414
*Oct 7 19:36:41.595: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: Deferred sending msg=0xC0A1FE18
*Oct 7 19:36:41.595: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 55
*Oct 7 19:36:41.595: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWConnectionCreated: context=0x676D969C
*Oct 7 19:36:41.595: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessConnCreated: gConnTab=0x676D969C, addr=198.102.22.150,
port=5060, connid=1, transport=UDP
*Oct 7 19:36:41.595: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportStopConnWaitTimer: Wait timer stopped for
connection=0xC0535414,addr=198.102.22.150, port=5060
*Oct 7 19:36:41.595: //37/081A0E098014/SIP/Transport/sipTransportPostInternalMsg: Posting Internal Msg type=0
*Oct 7 19:36:41.595: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 60
*Oct 7 19:36:41.595: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0xC0A1FE18, addr=198.102.22.150,
port=5060, connId=1 for UDP
*Oct 7 19:36:41.595: //37/081A0E098014/SIP/Info/sentByeDisconnecting: Sent Bye Request, starting DisconnectTimer
*Oct 7 19:36:41.595: //37/081A0E098014/SIP/State/sipSPIChangeState: 0x708E70F0 : State change from (STATE_SENT_SUCCESS, SUBSTATE_NONE) to
(STATE_DISCONNECTING, SUBSTATE_NONE)
*Oct 7 19:36:41.595: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
BYE sip:5085554300@198.102.22.150:5060 SIP/2.0
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK242A
From: <6175559056>;tag=580B64-128D6175559056>
To: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
Date: Thu, 07 Oct 2010 19:36:41 GMT
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
User-Agent: Cisco-SIPGateway/IOS-12.x
Max-Forwards: 70
Timestamp: 1286480201
CSeq: 101 BYE
Reason: Q.850;cause=47
Content-Length: 0
*Oct 7 19:36:42.095: //37/081A0E098014/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
*Oct 7 19:36:42.095: //37/081A0E098014/SIP/Info/sipSPISendBye: Associated container=0x69245A9C to Bye
*Oct 7 19:36:42.095: //37/081A0E098014/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer
*Oct 7 19:36:42.095: //37/081A0E098014/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is
FALSE
*Oct 7 19:36:42.095: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: msg=0xC0A1FE18, addr=198.102.22.150, port=5060,
sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x00000000
*Oct 7 19:36:42.095: //37/081A0E098014/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Oct 7 19:36:42.095: //37/081A0E098014/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Oct 7 19:36:42.095: //37/081A0E098014/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0xC0A1FE18
*Oct 7 19:36:42.095: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0xC0A1FE18, addr=198.102.22.150,
port=5060, connId=1 for UDP
*Oct 7 19:36:42.095: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
BYE sip:5085554300@198.102.22.150:5060 SIP/2.0
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK242A
From: <6175559056>;tag=580B64-128D6175559056>
To: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
Date: Thu, 07 Oct 2010 19:36:41 GMT
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
User-Agent: Cisco-SIPGateway/IOS-12.x
Max-Forwards: 70
Timestamp: 1286480202
CSeq: 101 BYE
Reason: Q.850;cause=47
Content-Length: 0
*Oct 7 19:36:42.791: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Oct 7 19:36:42.791: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Oct 7 19:36:42.791: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Oct 7 19:36:42.791: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:6175559056@24.11.70.246:5060 SIP/2.0
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
To: <6175559056>;tag=580B64-128D6175559056>
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
CSeq: 1 ACK
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3096-77fa4c12-2516
Max-Forwards: 70
Contact: <5085554300>5085554300>
Content-Length: 0
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x708E70F0
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 198.102.22.150,Port 5060,
Transport 1, SentBy Port 5060
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone pdt to SIP default timezone = GMT
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 198.102.22.150,Port 5060,
Transport 1, SentBy Port 5060
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/Error/sact_disconnecting_new_message_request: Unexpected ACK
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 198.102.22.150:5060
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x708E70F0
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK
From: <6175559056>;tag=580B64-128D6175559056>
To: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
CSeq: 101 BYE
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK242A
Content-Length: 0
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/Info/sipSPIIcpifUpdate: CallState: 3 Playout: 0 DiscTime:577674 ConnTime 577418
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/State/sipSPIChangeState: 0x708E70F0 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to
(STATE_DEAD, SUBSTATE_NONE)
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x708E70F0
State of The Call : STATE_DEAD
TCP Sockets Used : NO
Calling Number : 5085554300
Called Number : 6175559056
Source IP Address (Sig ): 24.11.70.246
Destn SIP Req Addr:Port : 198.102.22.150:5060
Destn SIP Resp Addr:Port : 198.102.22.150:5060
Destination Name : 198.102.22.150
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/Call/sipSPIMediaCallInfo:
Number of Media Streams: 1
Media Stream : 1
Negotiated Codec : g729r8
Negotiated Codec Bytes : 20
Negotiated Dtmf-relay : 0
Dtmf-relay Payload : 0
Source IP Address (Media): 24.11.70.246
Source IP Port (Media): 17440
Destn IP Address (Media): 198.102.22.157
Destn IP Port (Media): 17056
Orig Destn IP Address:Port (Media): 0.0.0.0:0
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/Call/sipSPICallInfo:
Disconnect Cause (CC) : 47
Disconnect Cause (SIP) : 200
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 25
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[35] removed.
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x708E70F0
key=76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.1576175559056
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x708E70F0
key=76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157580B64-128D
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be
free'd
*Oct 7 19:36:42.795: //37/081A0E098014/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 708E70F0
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[35]
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK
From: <6175559056>;tag=580B64-128D6175559056>
To: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae3090-77fa36b5-4fc05085554300>
Call-ID: 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
CSeq: 101 BYE
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK242A
Content-Length: 0
*Oct 7 19:36:42.795: //-1/xxxxxxxxxxxx/SIP/Error/sipSPILocateInviteDialogCCB: Could not find ccb for response
10-07-2010 01:26 PM
Here's the output of the voip ccapi inout debug
Syslog logging: enabled (12 messages dropped, 2 messages rate-limited,
0 flushes, 0 overruns, xml disabled, filtering disabled)
No Active Message Discriminator.
No Inactive Message Discriminator.
Console logging: disabled
Monitor logging: disabled
Buffer logging: level debugging, 2044 messages logged, xml disabled,
filtering disabled
Logging Exception size (4096 bytes)
Count and timestamp logging messages: disabled
No active filter modules.
Trap logging: level informational, 87 message lines logged
Log Buffer (10000000 bytes):
*Oct 7 20:22:13.671: //58/xxxxxxxxxxxx/CCAPI/cc_api_caps_ind:
Call Entry Is Not Found
*Oct 7 20:22:13.671: //-1/67CD79C88030/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=5085554300
----- ccCallInfo IE subfields -----
cisco-ani=5085554300
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=6175559056
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
*Oct 7 20:22:13.671: //-1/67CD79C88030/CCAPI/cc_api_call_setup_ind_common:
Interface=0xC02B8C6C, Call Info(
Calling Number=5085554300,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=6175559056(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
Incoming Dial-peer=10, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=58
*Oct 7 20:22:13.671: //-1/67CD79C88030/CCAPI/ccCheckClipClir:
In: Calling Number=5085554300(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Oct 7 20:22:13.671: //-1/67CD79C88030/CCAPI/ccCheckClipClir:
Out: Calling Number=5085554300(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Oct 7 20:22:13.671: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Oct 7 20:22:13.671: :cc_get_feature_vsa malloc success
*Oct 7 20:22:13.671: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Oct 7 20:22:13.671: cc_get_feature_vsa count is 1
*Oct 7 20:22:13.671: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Oct 7 20:22:13.671: :FEATURE_VSA attributes are: feature_name:0,fearture_time:3225558184,feature_id:18
*Oct 7 20:22:13.671: //58/67CD79C88030/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=5085554300(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=6175559056(TON=Unknown, NPI=Unknown))
*Oct 7 20:22:13.671: //58/67CD79C88030/CCAPI/cc_process_call_setup_ind:
Event=0xC04323F8
*Oct 7 20:22:13.671: //58/67CD79C88030/CCAPI/ccCallSetContext:
Context=0x692952FC
*Oct 7 20:22:13.671: //58/67CD79C88030/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 58 with tag 10 to app "_ManagedAppProcess_Default"
*Oct 7 20:22:13.671: //58/67CD79C88030/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
*Oct 7 20:22:13.671: //58/67CD79C88030/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=20001, Params=0x692960A4, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
*Oct 7 20:22:13.671: //58/67CD79C88030/CCAPI/ccCheckClipClir:
In: Calling Number=5085554300(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Oct 7 20:22:13.671: //58/67CD79C88030/CCAPI/ccCheckClipClir:
Out: Calling Number=5085554300(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Oct 7 20:22:13.671: //58/67CD79C88030/CCAPI/ccCallSetupRequest:
Destination Pattern=6175559056$, Called Number=6175559056, Digit Strip=TRUE
*Oct 7 20:22:13.671: //58/67CD79C88030/CCAPI/ccCallSetupRequest:
Calling Number=5085554300(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=6175559056(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=MASSACHUSETTS
Account Number=5085554300, Final Destination Flag=TRUE,
Guid=67CD79C8-D187-11DF-8030-F61ABE3841C5, Outgoing Dial-peer=20001
*Oct 7 20:22:13.675: //58/67CD79C88030/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=5085554300
----- ccCallInfo IE subfields -----
cisco-ani=5085554300
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=6175559056
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
*Oct 7 20:22:13.675: //58/67CD79C88030/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x67BC1158, Interface Type=6, Destination=, Mode=0x0,
Call Params(Calling Number=5085554300,(Calling Name=MASSACHUSETTS )(TON=Unknown, NPI=Unknown, Screening=Not Screened,
Presentation=Allowed),
Called Number=6175559056(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=)
*Oct 7 20:22:13.675: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Oct 7 20:22:13.675: :cc_get_feature_vsa malloc success
*Oct 7 20:22:13.675: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Oct 7 20:22:13.675: cc_get_feature_vsa count is 2
*Oct 7 20:22:13.675: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Oct 7 20:22:13.675: :FEATURE_VSA attributes are: feature_name:0,fearture_time:3225558400,feature_id:19
*Oct 7 20:22:13.675: //59/67CD79C88030/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1
*Oct 7 20:22:13.675: //59/67CD79C88030/CCAPI/ccCallSetContext:
Context=0x69296054
*Oct 7 20:22:13.675: //58/67CD79C88030/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=20001
*Oct 7 20:22:13.675: //59/67CD79C88030/CCAPI/cc_api_update_call_info:
Interface=0x67BC1158, Call Id=0x3B
*Oct 7 20:22:13.675: //59/67CD79C88030/CCAPI/cc_api_call_proceeding:
Interface=0x67BC1158, Progress Indication=NULL(0)
*Oct 7 20:22:13.675: //59/67CD79C88030/CCAPI/cc_api_call_alert:
Interface=0x67BC1158, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
*Oct 7 20:22:13.675: //59/67CD79C88030/CCAPI/cc_api_call_alert:
Call Entry(Retry Count=0, Responsed=TRUE)
*Oct 7 20:22:13.679: //58/67CD79C88030/CCAPI/ccCallAlert:
Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
*Oct 7 20:22:13.679: //58/67CD79C88030/CCAPI/ccCallAlert:
Call Entry(Responsed=TRUE, AlertSent=TRUE)
*Oct 7 20:22:20.723: //59/67CD79C88030/CCAPI/cc_api_call_connected:
Interface=0x67BC1158, Data Bitmask=0x1, Progress Indication=NULL(0),
Connection Handle=0
*Oct 7 20:22:20.723: //59/67CD79C88030/CCAPI/cc_api_call_connected:
Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
*Oct 7 20:22:20.723: //58/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:
(confID=0x67D9E898, callID1=0x3A, callID2=0x3B, tag=0x0)
*Oct 7 20:22:20.723: //58/67CD79C88030/CCAPI/ccConferenceCreate:
Conference Id=0x67D9E898, Call Id1=58, Call Id2=59, Tag=0x0
*Oct 7 20:22:20.723: //58/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:
*Oct 7 20:22:20.723: cc_api_get_xcode_stream : 4368
*Oct 7 20:22:20.723: //58/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0x9, Source Interface=0xC02B8C6C, Source Call Id=58,
Destination Call Id=59, Disposition=0x0, Tag=0x0
*Oct 7 20:22:20.723: //59/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0x9, Source Interface=0x67BC1158, Source Call Id=59,
Destination Call Id=58, Disposition=0x0, Tag=0xFFFFFFFF
*Oct 7 20:22:20.723: //58/67CD79C88030/CCAPI/cc_generic_bridge_done:
Conference Id=0x9, Source Interface=0x67BC1158, Source Call Id=59,
Destination Call Id=58, Disposition=0x0, Tag=0xFFFFFFFF
*Oct 7 20:22:20.723: //58/67CD79C88030/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0x9, Destination Call Id=59)
*Oct 7 20:22:20.723: //59/67CD79C88030/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0x9, Destination Call Id=58)
*Oct 7 20:22:20.723: //59/67CD79C88030/CCAPI/cc_api_caps_ind:
Destination Interface=0xC02B8C6C, Destination Call Id=58, Source Call Id=59,
Caps(Codec=0x1, Fax Rate=0x1, Vad=0x1,
Modem=0x0, Codec Bytes=20, Signal Type=3)
*Oct 7 20:22:20.723: //59/67CD79C88030/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=250(ms), Fax Nom=300(ms))
*Oct 7 20:22:20.723: //58/67CD79C88030/CCAPI/cc_api_caps_ind:
Destination Interface=0x67BC1158, Destination Call Id=59, Source Call Id=58,
Caps(Codec=0x4, Fax Rate=0x2, Vad=0x1,
Modem=0x0, Codec Bytes=20, Signal Type=2)
*Oct 7 20:22:20.723: //58/67CD79C88030/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=250(ms), Fax Nom=300(ms))
*Oct 7 20:22:20.723: //58/67CD79C88030/CCAPI/cc_api_caps_ack:
Destination Interface=0x67BC1158, Destination Call Id=59, Source Call Id=58,
Caps(Codec=g729r8(0x4), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1),
Modem=OFF(0x0), Codec Bytes=20, Signal Type=2, Seq Num Start=4208)
*Oct 7 20:22:20.723: //59/67CD79C88030/CCAPI/cc_api_caps_ack:
Destination Interface=0xC02B8C6C, Destination Call Id=58, Source Call Id=59,
Caps(Codec=g729r8(0x4), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1),
Modem=OFF(0x0), Codec Bytes=20, Signal Type=2, Seq Num Start=4208)
*Oct 7 20:22:20.723: //58/67CD79C88030/CCAPI/cc_api_call_disconnected:
Cause Value=47, Interface=0x67BC1158, Call Id=58
*Oct 7 20:22:20.723: //58/67CD79C88030/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=47, Retry Count=0)
*Oct 7 20:22:20.723: //58/67CD79C88030/CCAPI/cc_process_notify_bridge_done:
Conference Id=0x9, Call Id1=58, Call Id2=59
*Oct 7 20:22:20.727: //59/67CD79C88030/CCAPI/cc_api_voice_mode_event:
Call Id=59
*Oct 7 20:22:20.727: //59/67CD79C88030/CCAPI/cc_api_voice_mode_event:
Call Entry(Context=0x69296054)
*Oct 7 20:22:20.727: //58/67CD79C88030/CCAPI/ccCallConnect:
Progress Indication=NULL(0), Data Bitmask=0x1
*Oct 7 20:22:20.727: //58/67CD79C88030/CCAPI/ccCallConnect:
Call Entry(Connected=TRUE, Responsed=TRUE)
*Oct 7 20:22:20.727: //58/67CD79C88030/CCAPI/cc_api_get_ccm_detected:
CallInfo(ccm detected=FALSE)
*Oct 7 20:22:20.727: //59/67CD79C88030/CCAPI/ccCallFeature:
Feature Type=25, Call Id=59
*Oct 7 20:22:20.727: //58/67CD79C88030/CCAPI/ccConferenceDestroy:
Conference Id=0x9, Tag=0x0
*Oct 7 20:22:20.727: //58/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done:
Conference Id=0x9, Source Interface=0xC02B8C6C, Source Call Id=58,
Destination Call Id=59, Disposition=0x0, Tag=0x0
*Oct 7 20:22:20.727: //59/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done:
Conference Id=0x9, Source Interface=0x67BC1158, Source Call Id=59,
Destination Call Id=58, Disposition=0x0, Tag=0x0
*Oct 7 20:22:20.727: //58/67CD79C88030/CCAPI/cc_generic_bridge_done:
Conference Id=0x9, Source Interface=0x67BC1158, Source Call Id=59,
Destination Call Id=58, Disposition=0x0, Tag=0x0
*Oct 7 20:22:20.731: //58/67CD79C88030/CCAPI/ccCallDisconnect:
Cause Value=47, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=47)
*Oct 7 20:22:20.731: //58/67CD79C88030/CCAPI/ccCallDisconnect:
Cause Value=47, Call Entry(Responsed=TRUE, Cause Value=47)
*Oct 7 20:22:20.731: //59/67CD79C88030/CCAPI/ccCallDisconnect:
Cause Value=47, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
*Oct 7 20:22:20.731: //59/67CD79C88030/CCAPI/ccCallDisconnect:
Cause Value=47, Call Entry(Responsed=TRUE, Cause Value=47)
*Oct 7 20:22:20.731: //59/67CD79C88030/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
*Oct 7 20:22:20.731: //59/67CD79C88030/CCAPI/cc_api_call_feature:
Feature Type=6, Interface=0x67BC1158, Call Id=59
*Oct 7 20:22:20.735: //59/67CD79C88030/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x67BC1158, Tag=0x0, Call Id=59,
Call Entry(Disconnect Cause=47, Voice Class Cause Code=0, Retry Count=0)
*Oct 7 20:22:20.735: //59/67CD79C88030/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Oct 7 20:22:20.735: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Oct 7 20:22:20.735: :cc_free_feature_vsa freeing C0421D78
*Oct 7 20:22:20.735: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Oct 7 20:22:20.735: vsacount in free is 1
*Oct 7 20:22:22.011: //58/67CD79C88030/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0xC02B8C6C, Tag=0x0, Call Id=58,
Call Entry(Disconnect Cause=47, Voice Class Cause Code=0, Retry Count=0)
*Oct 7 20:22:22.011: //58/67CD79C88030/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Oct 7 20:22:22.011: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Oct 7 20:22:22.011: :cc_free_feature_vsa freeing C0421CA0
*Oct 7 20:22:22.011: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Oct 7 20:22:22.011: vsacount in free is 0
10-07-2010 03:19 PM
Follow SIP Call ID 76223F99-D18811DF-BDB7CF8F-B576B345@198.102.22.157
Your provider is sending an INVITE before the call connects. That's a spec violation. It should send UPDATE if it needs to change parameters before the call establishes. I'm thinking that may cause call state issues, and may be the root issue.
Perhaps the second INVITE is coming in because they never got our 100 Trying. Verify that.
BTW, you shouldn't need a transcoder for this flow, since it is just g729 to a CME phone.
Also, when debugging, run all debugs at the same time. I see the disconnect throws here:
*Oct 7 19:36:40.235: //37/081A0E098014/SIP/Info/act_sentsucc_disconnect: Received POTS Disconnect - Holding BYE till we receive ACK or runs
But I'd want to see what happens during that event in the CCPAI debugs, which I can't since they weren't run in parallel.
10-07-2010 03:36 PM
Steven,
Attached is the debug output in parallel. Makes sense to me with the transcoder. The SIP flow is something I don't understand very well but will do some reading up. Thanks for your help.
=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2010.10.07 18:02:25 =~=~=~=~=~=~=~=~=~=~=~=
sh logg
Syslog logging: enabled (12 messages dropped, 2 messages rate-limited,
0 flushes, 0 overruns, xml disabled, filtering disabled)
No Active Message Discriminator.
No Inactive Message Discriminator.
Console logging: disabled
Monitor logging: level debugging, 22 messages logged, xml disabled,
filtering disabled
Buffer logging: level debugging, 2562 messages logged, xml disabled,
filtering disabled
Logging Exception size (4096 bytes)
Count and timestamp logging messages: disabled
No active filter modules.
Trap logging: level informational, 131 message lines logged
Log Buffer (10000000 bytes):
002219: *Oct 7 22:00:54.219: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:6175559056@24.11.70.246:5060 SIP/2.0
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
To: <6175559056>6175559056>
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
CSeq: 1 INVITE
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5262-787e53b1-4e20
Max-Forwards: 70
Contact: <5085554300>5085554300>
Content-Type: application/SDP
Content-Length: 220
v=0
o=CiscoSystemsSIP-GW-UserAgent 1695 4616 IN IP4 198.102.22.157
s=SIP Call
c=IN IP4 198.102.22.157
t=0 0
m=audio 17832 RTP/AVP 18
c=IN IP4 198.102.22.157
a=fmtp:18 annexb=no
a=ptime:20
a=rtpmap:18 G729/8000
002220: *Oct 7 22:00:54.223: //112/xxxxxxxxxxxx/CCAPI/cc_api_caps_ind:
Call Entry Is Not Found
002221: *Oct 7 22:00:54.223: //-1/30B95904806C/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=5085554300
----- ccCallInfo IE subfields -----
cisco-ani=5085554300
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=6175559056
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
002222: *Oct 7 22:00:54.223: //-1/30B95904806C/CCAPI/cc_api_call_setup_ind_common:
Interface=0xC02B8C6C, Call Info(
Calling Number=5085554300,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened,
Presentation=Allowed),
Called Number=6175559056(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
Incoming Dial-peer=10, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=112
002223: *Oct 7 22:00:54.223: //-1/30B95904806C/CCAPI/ccCheckClipClir:
In: Calling Number=5085554300(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
002224: *Oct 7 22:00:54.223: //-1/30B95904806C/CCAPI/ccCheckClipClir:
Out: Calling Number=5085554300(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
002225: *Oct 7 22:00:54.223: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
002226: *Oct 7 22:00:54.223: :cc_get_feature_vsa malloc success
002227: *Oct 7 22:00:54.223: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
002228: *Oct 7 22:00:54.223: cc_get_feature_vsa count is 1
002229: *Oct 7 22:00:54.223: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
002230: *Oct 7 22:00:54.223: :FEATURE_VSA attributes are:
feature_name:0,fearture_time:3225558184,feature_id:48
002231: *Oct 7 22:00:54.223: //112/30B95904806C/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=5085554300(TON=Unknown, NPI=Unknown, Screening=Not Screened,
Presentation=Allowed),
Called Number=6175559056(TON=Unknown, NPI=Unknown))
002232: *Oct 7 22:00:54.223: //112/30B95904806C/CCAPI/cc_process_call_setup_ind:
Event=0xC04323F8
002233: *Oct 7 22:00:54.223: //112/30B95904806C/CCAPI/ccCallSetContext:
Context=0x69287D7C
002234: *Oct 7 22:00:54.223: //112/30B95904806C/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 112 with tag 10 to app "_ManagedAppProcess_Default"
002235: *Oct 7 22:00:54.223: //112/30B95904806C/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
002236: *Oct 7 22:00:54.223: //112/30B95904806C/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=20001, Params=0x69296DFC, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
002237: *Oct 7 22:00:54.223: //112/30B95904806C/CCAPI/ccCheckClipClir:
In: Calling Number=5085554300(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
002238: *Oct 7 22:00:54.223: //112/30B95904806C/CCAPI/ccCheckClipClir:
Out: Calling Number=5085554300(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
002239: *Oct 7 22:00:54.223: //112/30B95904806C/CCAPI/ccCallSetupRequest:
Destination Pattern=6175559056$, Called Number=6175559056, Digit Strip=TRUE
002240: *Oct 7 22:00:54.223: //112/30B95904806C/CCAPI/ccCallSetupRequest:
Calling Number=5085554300(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=6175559056(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=MASSACHUSETTS
Account Number=5085554300, Final Destination Flag=TRUE,
Guid=30B95904-D195-11DF-806C-F61ABE3841C5, Outgoing Dial-peer=20001
002241: *Oct 7 22:00:54.227: //112/30B95904806C/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=5085554300
----- ccCallInfo IE subfields -----
cisco-ani=5085554300
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=6175559056
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
002242: *Oct 7 22:00:54.227: //112/30B95904806C/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x67BC1158, Interface Type=6, Destination=, Mode=0x0,
Call Params(Calling Number=5085554300,(Calling Name=MASSACHUSETTS )(TON=Unknown, NPI=Unknown,
Screening=Not Screened, Presentation=Allowed),
Called Number=6175559056(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=)
002243: *Oct 7 22:00:54.227: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
002244: *Oct 7 22:00:54.227: :cc_get_feature_vsa malloc success
002245: *Oct 7 22:00:54.227: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
002246: *Oct 7 22:00:54.227: cc_get_feature_vsa count is 2
002247: *Oct 7 22:00:54.227: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
002248: *Oct 7 22:00:54.227: :FEATURE_VSA attributes are:
feature_name:0,fearture_time:3225557536,feature_id:49
002249: *Oct 7 22:00:54.227: //113/30B95904806C/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1
002250: *Oct 7 22:00:54.227: //113/30B95904806C/CCAPI/ccCallSetContext:
Context=0x69296DAC
002251: *Oct 7 22:00:54.227: //112/30B95904806C/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=20001
002252: *Oct 7 22:00:54.227: //113/30B95904806C/CCAPI/cc_api_update_call_info:
Interface=0x67BC1158, Call Id=0x71
002253: *Oct 7 22:00:54.227: //113/30B95904806C/CCAPI/cc_api_call_proceeding:
Interface=0x67BC1158, Progress Indication=NULL(0)
002254: *Oct 7 22:00:54.227: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5262-787e53b1-4e20
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
To: <6175559056>;tag=DC2810-B336175559056>
Date: Thu, 07 Oct 2010 22:00:54 GMT
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 INVITE
Allow-Events: telephone-event
Content-Length: 0
002255: *Oct 7 22:00:54.227: //113/30B95904806C/CCAPI/cc_api_call_alert:
Interface=0x67BC1158, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
002256: *Oct 7 22:00:54.231: //113/30B95904806C/CCAPI/cc_api_call_alert:
Call Entry(Retry Count=0, Responsed=TRUE)
002257: *Oct 7 22:00:54.231: //112/30B95904806C/CCAPI/ccCallAlert:
Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
002258: *Oct 7 22:00:54.231: //112/30B95904806C/CCAPI/ccCallAlert:
Call Entry(Responsed=TRUE, AlertSent=TRUE)
002259: *Oct 7 22:00:54.231: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5262-787e53b1-4e20
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
To: <6175559056>;tag=DC2810-B336175559056>
Date: Thu, 07 Oct 2010 22:00:54 GMT
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Contact: <6175559056>6175559056>
Content-Length: 0
002260: *Oct 7 22:00:54.611: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:6175559056@24.11.70.246:5060 SIP/2.0
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
To: <6175559056>6175559056>
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
CSeq: 1 INVITE
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5262-787e53b1-4e20
Max-Forwards: 70
Contact: <5085554300>5085554300>
Content-Type: application/SDP
Content-Length: 220
v=0
o=CiscoSystemsSIP-GW-UserAgent 1695 4616 IN IP4 198.102.22.157
s=SIP Call
c=IN IP4 198.102.22.157
t=0 0
m=audio 17832 RTP/AVP 18
c=IN IP4 198.102.22.157
a=fmtp:18 annexb=no
a=ptime:20
a=rtpmap:18 G729/8000
002261: *Oct 7 22:00:54.611: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5262-787e53b1-4e20
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
To: <6175559056>;tag=DC2810-B336175559056>
Date: Thu, 07 Oct 2010 22:00:54 GMT
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Contact: <6175559056>6175559056>
Content-Length: 0
002262: *Oct 7 22:00:55.419: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:6175559056@24.11.70.246:5060 SIP/2.0
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
To: <6175559056>6175559056>
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
CSeq: 1 INVITE
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5262-787e53b1-4e20
Max-Forwards: 70
Contact: <5085554300>5085554300>
Content-Type: application/SDP
Content-Length: 220
v=0
o=CiscoSystemsSIP-GW-UserAgent 1695 4616 IN IP4 198.102.22.157
s=SIP Call
c=IN IP4 198.102.22.157
t=0 0
m=audio 17832 RTP/AVP 18
c=IN IP4 198.102.22.157
a=fmtp:18 annexb=no
a=ptime:20
a=rtpmap:18 G729/8000
002263: *Oct 7 22:00:55.423: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5262-787e53b1-4e20
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
To: <6175559056>;tag=DC2810-B336175559056>
Date: Thu, 07 Oct 2010 22:00:55 GMT
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Contact: <6175559056>6175559056>
Content-Length: 0
002264: *Oct 7 22:00:56.079: //113/30B95904806C/CCAPI/cc_api_call_connected:
Interface=0x67BC1158, Data Bitmask=0x1, Progress Indication=NULL(0),
Connection Handle=0
002265: *Oct 7 22:00:56.079: //113/30B95904806C/CCAPI/cc_api_call_connected:
Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
002266: *Oct 7 22:00:56.079: //112/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:
(confID=0x67D9E970, callID1=0x70, callID2=0x71, tag=0x0)
002267: *Oct 7 22:00:56.079: //112/30B95904806C/CCAPI/ccConferenceCreate:
Conference Id=0x67D9E970, Call Id1=112, Call Id2=113, Tag=0x0
002268: *Oct 7 22:00:56.079: //112/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:
002269: *Oct 7 22:00:56.079: cc_api_get_xcode_stream : 4368
002270: *Oct 7 22:00:56.079: //112/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0xC, Source Interface=0xC02B8C6C, Source Call Id=112,
Destination Call Id=113, Disposition=0x0, Tag=0x0
002271: *Oct 7 22:00:56.079: //113/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0xC, Source Interface=0x67BC1158, Source Call Id=113,
Destination Call Id=112, Disposition=0x0, Tag=0xFFFFFFFF
002272: *Oct 7 22:00:56.079: //112/30B95904806C/CCAPI/cc_generic_bridge_done:
Conference Id=0xC, Source Interface=0x67BC1158, Source Call Id=113,
Destination Call Id=112, Disposition=0x0, Tag=0xFFFFFFFF
002273: *Oct 7 22:00:56.079: //112/30B95904806C/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0xC, Destination Call Id=113)
002274: *Oct 7 22:00:56.079: //113/30B95904806C/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0xC, Destination Call Id=112)
002275: *Oct 7 22:00:56.083: //113/30B95904806C/CCAPI/cc_api_caps_ind:
Destination Interface=0xC02B8C6C, Destination Call Id=112, Source Call Id=113,
Caps(Codec=0x1, Fax Rate=0x1, Vad=0x1,
Modem=0x0, Codec Bytes=20, Signal Type=3)
002276: *Oct 7 22:00:56.083: //113/30B95904806C/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=250(ms), Fax Nom=300(ms))
002277: *Oct 7 22:00:56.083: //112/30B95904806C/CCAPI/cc_api_caps_ind:
Destination Interface=0x67BC1158, Destination Call Id=113, Source Call Id=112,
Caps(Codec=0x4, Fax Rate=0x2, Vad=0x1,
Modem=0x0, Codec Bytes=20, Signal Type=2)
002278: *Oct 7 22:00:56.083: //112/30B95904806C/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=250(ms), Fax Nom=300(ms))
002279: *Oct 7 22:00:56.083: //112/30B95904806C/CCAPI/cc_api_caps_ack:
Destination Interface=0x67BC1158, Destination Call Id=113, Source Call Id=112,
Caps(Codec=g729r8(0x4), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1),
Modem=OFF(0x0), Codec Bytes=20, Signal Type=2, Seq Num Start=9123)
002280: *Oct 7 22:00:56.083: //113/30B95904806C/CCAPI/cc_api_caps_ack:
Destination Interface=0xC02B8C6C, Destination Call Id=112, Source Call Id=113,
Caps(Codec=g729r8(0x4), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1),
Modem=OFF(0x0), Codec Bytes=20, Signal Type=2, Seq Num Start=9123)
002281: *Oct 7 22:00:56.083: //112/30B95904806C/CCAPI/cc_process_notify_bridge_done:
Conference Id=0xC, Call Id1=112, Call Id2=113
002282: *Oct 7 22:00:56.083: //112/30B95904806C/CCAPI/cc_api_call_disconnected:
Cause Value=47, Interface=0x67BC1158, Call Id=112
002283: *Oct 7 22:00:56.083: //112/30B95904806C/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=47, Retry Count=0)
002284: *Oct 7 22:00:56.083: //113/30B95904806C/CCAPI/cc_api_voice_mode_event:
Call Id=113
002285: *Oct 7 22:00:56.083: //113/30B95904806C/CCAPI/cc_api_voice_mode_event:
Call Entry(Context=0x69296DAC)
002286: *Oct 7 22:00:56.083: //112/30B95904806C/CCAPI/ccCallConnect:
Progress Indication=NULL(0), Data Bitmask=0x1
002287: *Oct 7 22:00:56.083: //112/30B95904806C/CCAPI/ccCallConnect:
Call Entry(Connected=TRUE, Responsed=TRUE)
002288: *Oct 7 22:00:56.083: //112/30B95904806C/CCAPI/cc_api_get_ccm_detected:
CallInfo(ccm detected=FALSE)
002289: *Oct 7 22:00:56.083: //113/30B95904806C/CCAPI/ccCallFeature:
Feature Type=25, Call Id=113
002290: *Oct 7 22:00:56.087: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5262-787e53b1-4e20
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
To: <6175559056>;tag=DC2810-B336175559056>
Date: Thu, 07 Oct 2010 22:00:55 GMT
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Contact: <6175559056>6175559056>
Supported: replaces
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 220
v=0
o=CiscoSystemsSIP-GW-UserAgent 2787 9704 IN IP4 24.11.70.246
s=SIP Call
c=IN IP4 24.11.70.246
t=0 0
m=audio 18200 RTP/AVP 18
c=IN IP4 24.11.70.246
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
002291: *Oct 7 22:00:56.087: //112/30B95904806C/CCAPI/ccConferenceDestroy:
Conference Id=0xC, Tag=0x0
002292: *Oct 7 22:00:56.087: //112/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done:
Conference Id=0xC, Source Interface=0xC02B8C6C, Source Call Id=112,
Destination Call Id=113, Disposition=0x0, Tag=0x0
002293: *Oct 7 22:00:56.087: //113/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done:
Conference Id=0xC, Source Interface=0x67BC1158, Source Call Id=113,
Destination Call Id=112, Disposition=0x0, Tag=0x0
002294: *Oct 7 22:00:56.087: //112/30B95904806C/CCAPI/cc_generic_bridge_done:
Conference Id=0xC, Source Interface=0x67BC1158, Source Call Id=113,
Destination Call Id=112, Disposition=0x0, Tag=0x0
002295: *Oct 7 22:00:56.087: //112/30B95904806C/CCAPI/ccCallDisconnect:
Cause Value=47, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=47)
002296: *Oct 7 22:00:56.087: //112/30B95904806C/CCAPI/ccCallDisconnect:
Cause Value=47, Call Entry(Responsed=TRUE, Cause Value=47)
002297: *Oct 7 22:00:56.087: //113/30B95904806C/CCAPI/ccCallDisconnect:
Cause Value=47, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
002298: *Oct 7 22:00:56.087: //113/30B95904806C/CCAPI/ccCallDisconnect:
Cause Value=47, Call Entry(Responsed=TRUE, Cause Value=47)
002299: *Oct 7 22:00:56.087: //113/30B95904806C/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
002300: *Oct 7 22:00:56.087: //113/30B95904806C/CCAPI/cc_api_call_feature:
Feature Type=6, Interface=0x67BC1158, Call Id=113
002301: *Oct 7 22:00:56.091: //113/30B95904806C/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x67BC1158, Tag=0x0, Call Id=113,
Call Entry(Disconnect Cause=47, Voice Class Cause Code=0, Retry Count=0)
002302: *Oct 7 22:00:56.091: //113/30B95904806C/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
002303: *Oct 7 22:00:56.091: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
002304: *Oct 7 22:00:56.091: :cc_free_feature_vsa freeing C0421A18
002305: *Oct 7 22:00:56.091: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
002306: *Oct 7 22:00:56.091: vsacount in free is 1
002307: *Oct 7 22:00:56.587: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5262-787e53b1-4e20
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
To: <6175559056>;tag=DC2810-B336175559056>
Date: Thu, 07 Oct 2010 22:00:55 GMT
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Contact: <6175559056>6175559056>
Supported: replaces
Reason: Q.850;cause=47
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 220
v=0
o=CiscoSystemsSIP-GW-UserAgent 2787 9704 IN IP4 24.11.70.246
s=SIP Call
c=IN IP4 24.11.70.246
t=0 0
m=audio 18200 RTP/AVP 18
c=IN IP4 24.11.70.246
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
002308: *Oct 7 22:00:56.831: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:6175559056@24.11.70.246:5060 SIP/2.0
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
To: <6175559056>;tag=DC2810-B336175559056>
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
CSeq: 1 ACK
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5265-787e5de2-6477
Max-Forwards: 70
Contact: <5085554300>5085554300>
Content-Length: 0
002309: *Oct 7 22:00:56.831: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
BYE sip:5085554300@198.102.22.150:5060 SIP/2.0
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK58B15
From: <6175559056>;tag=DC2810-B336175559056>
To: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
Date: Thu, 07 Oct 2010 22:00:56 GMT
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
User-Agent: Cisco-SIPGateway/IOS-12.x
Max-Forwards: 70
Timestamp: 1286488856
CSeq: 101 BYE
Reason: Q.850;cause=47
Content-Length: 0
002310: *Oct 7 22:00:57.191: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:6175559056@24.11.70.246:5060 SIP/2.0
From: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
To: <6175559056>;tag=DC2810-B336175559056>
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
CSeq: 1 ACK
Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5265-787e5de2-6477
Max-Forwards: 70
Contact: <5085554300>5085554300>
Content-Length: 0
002311: *Oct 7 22:00:57.331: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
BYE sip:5085554300@198.102.22.150:5060 SIP/2.0
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK58B15
From: <6175559056>;tag=DC2810-B336175559056>
To: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
Date: Thu, 07 Oct 2010 22:00:57 GMT
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
User-Agent: Cisco-SIPGateway/IOS-12.x
Max-Forwards: 70
Timestamp: 1286488857
CSeq: 101 BYE
Reason: Q.850;cause=47
Content-Length: 0
002312: *Oct 7 22:00:57.431: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK
From: <6175559056>;tag=DC2810-B336175559056>
To: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
CSeq: 101 BYE
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK58B15
Content-Length: 0
002313: *Oct 7 22:00:57.431: //112/30B95904806C/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0xC02B8C6C, Tag=0x0, Call Id=112,
Call Entry(Disconnect Cause=47, Voice Class Cause Code=0, Retry Count=0)
002314: *Oct 7 22:00:57.431: //112/30B95904806C/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
002315: *Oct 7 22:00:57.431: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
002316: *Oct 7 22:00:57.431: :cc_free_feature_vsa freeing C0421CA0
002317: *Oct 7 22:00:57.431: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
002318: *Oct 7 22:00:57.431: vsacount in free is 0
002319: *Oct 7 22:00:57.939: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK
From: <6175559056>;tag=DC2810-B336175559056>
To: "MASSACHUSETTS "<5085554300>;tag=961666c6-13c4-4cae5262-787e53b1-59235085554300>
Call-ID: 9EC0EE6C-D19C11DF-8AEECF8F-B576B345@198.102.22.157
CSeq: 101 BYE
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK58B15
Content-Length: 0
10-07-2010 08:08 PM
Hmm....seems the issue is more of network latency related than codec related.
I notice a 2nd Invite reTx ~400ms after we have sent 18x for the first Invite.
And ~800ms later another Invite reTx comes in.
Looking at the timing of these msgs and since it is the same Invite being reTX
(same CSeq header) it seems the provider is not seeing 1xx (100, 180) from
our side/CME or is timing out waiting for it...
I also noticed that there is no Allow: or Supported: header in the incoming Invite
so even if we enable provisional response, it may not do anything.
Guess there is no harm in trying it though....pl. add following and test:
voice service voip
sip
rel1xx require "100rel" <--- add as u see it here
Regardless, you should go back to your provider and ask them to verify if they are
seeing 100/180 from us for the initial Invite or not (which we are certainly sending)
If yes, then why are they reTx subsequent Invites ? If no, then we need to figure
out where they are getting dropped along the way as debugs does show it getting Tx.
Either way, it seems they shd bump up the timer to wait for provisional response to
Invite. Not sure what SIP server/proxy they are using but on IOS GW, here's what u do:
sip-ua
timers trying 1000
Running following shd give u some idea abt RTD :
ping 198.102.22.150 source 24.11.70.246
DK
10-08-2010 09:11 AM
I spoke with the SIP provider this morning and he can see the 100/180 messages. He couldn't explain why we are seeing multiple INVITE messages though. But since we are seeing the 2nd one 400ms after the first then I would guess their timeout must be ~300. This is a slow satellite link so that may be problematic. I am seeing round trip ping times of 600 ms up to 1.5 s.
I am posting a debug as a result from calling from the CME to the PSTN. You'll see a 501 error and a disconnect cause code of 79 (Service or option not implemented). Would this also me due to a latency issue or do I have another problem altogether when dialing out?
=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2010.10.08 11:53:00 =~=~=~=~=~=~=~=~=~=~=~=
sh logg
Syslog logging: enabled (12 messages dropped, 2 messages rate-limited,
0 flushes, 0 overruns, xml disabled, filtering disabled)
No Active Message Discriminator.
No Inactive Message Discriminator.
Console logging: disabled
Monitor logging: disabled
Buffer logging: level debugging, 7274 messages logged, xml disabled,
filtering disabled
Logging Exception size (4096 bytes)
Count and timestamp logging messages: disabled
No active filter modules.
Trap logging: level informational, 139 message lines logged
Log Buffer (10000000 bytes):
004831: *Oct 8 15:51:42.262: //-1/C78ACB3C80D4/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=
----- ccCallInfo IE subfields -----
cisco-ani=6175559034
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=0 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0
004832: *Oct 8 15:51:42.262: //-1/C78ACB3C80D4/CCAPI/cc_api_call_setup_ind_common:
Interface=0x67BC1158, Call Info(
Calling Number=6175559034,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened,
Presentation=Allowed),
Called Number=(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=FALSE,
Incoming Dial-peer=20001, Progress Indication=ORIGINATING SIDE IS NON ISDN(3), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=-1
004833: *Oct 8 15:51:42.262: //-1/C78ACB3C80D4/CCAPI/ccCheckClipClir:
In: Calling Number=6175559034(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
004834: *Oct 8 15:51:42.262: //-1/C78ACB3C80D4/CCAPI/ccCheckClipClir:
Out: Calling Number=6175559034(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
004835: *Oct 8 15:51:42.262: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
004836: *Oct 8 15:51:42.262: :cc_get_feature_vsa malloc success
004837: *Oct 8 15:51:42.262: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
004838: *Oct 8 15:51:42.262: cc_get_feature_vsa count is 1
004839: *Oct 8 15:51:42.262: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
004840: *Oct 8 15:51:42.262: :FEATURE_VSA attributes are:
feature_name:0,fearture_time:3225558184,feature_id:84
004841: *Oct 8 15:51:42.262: //321/C78ACB3C80D4/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=6175559034(TON=Unknown, NPI=Unknown, Screening=Not Screened,
Presentation=Allowed),
Called Number=(TON=Unknown, NPI=Unknown))
004842: *Oct 8 15:51:42.262: //321/C78ACB3C80D4/CCAPI/cc_process_call_setup_ind:
Event=0xC04311D8
004843: *Oct 8 15:51:42.262: //321/C78ACB3C80D4/CCAPI/ccCallSetContext:
Context=0x69291D9C
004844: *Oct 8 15:51:42.262: //321/C78ACB3C80D4/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 321 with tag 20001 to app "_ManagedAppProcess_Default"
004845: *Oct 8 15:51:42.266: //321/C78ACB3C80D4/CCAPI/ccCallSetupAck:
Call Id=321
004846: *Oct 8 15:51:42.266: //321/C78ACB3C80D4/CCAPI/cc_api_set_transfer_info:
Transfer Number=, Transfer Reason=0x0
004847: *Oct 8 15:51:42.266: //321/C78ACB3C80D4/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=TRUE, Tone=Dial Tone,
Tone Direction=Network, Params=0x0, Call Id=321
004848: *Oct 8 15:51:42.266: //321/C78ACB3C80D4/CCAPI/ccSetDigitTimeouts:
Initial Digit Timeout=-1000(ms), Inter Digit Timeout=-1000(ms)
004849: *Oct 8 15:51:42.266: //321/C78ACB3C80D4/CCAPI/ccSetDigitTimeouts:
Call Entry(Inter Digit Timeout=10000(ms), Initial Digit Timeout=10000(ms))
004850: *Oct 8 15:51:42.266: //321/xxxxxxxxxxxx/CCAPI/ccCallReportDigits:
(callID=0x141, digit_event=0x1, enable=TRUE, consume=FALSE)
004851: *Oct 8 15:51:42.266: //321/C78ACB3C80D4/CCAPI/ccCallReportDigits:
Enabled=TRUE, Call Id=321
004852: *Oct 8 15:51:42.266: //321/xxxxxxxxxxxx/CCAPI/cc_api_call_report_digits_done:
(vdbPtr=0x67BC1158, callID=0x141, disp=0, digit_event=0x1, enable=TRUE, consume=FALSE)
004853: *Oct 8 15:51:42.266: //321/C78ACB3C80D4/CCAPI/cc_api_call_report_digits_done:
Enabled=TRUE, Disposition=0x0, Interface=0x67BC1158, Call Id=321
004854: *Oct 8 15:51:42.266: //321/C78ACB3C80D4/CCAPI/cc_api_call_report_digits_done:
Call Entry(Initial Digit Timeout=10000(ms), Inter Digit Timeout=10000(ms))
004855: *Oct 8 15:51:42.486: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=1, DigitBeginFlags=0x0,
Rtp Timestamp=0x46C148, Rtp Expiration=0x0
004856: *Oct 8 15:51:42.486: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=1, Duration=100,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
004857: *Oct 8 15:51:42.486: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
004858: *Oct 8 15:51:42.614: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=6, DigitBeginFlags=0x0,
Rtp Timestamp=0x473E48, Rtp Expiration=0x0
004859: *Oct 8 15:51:42.614: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=6, Duration=100,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
004860: *Oct 8 15:51:42.614: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
004861: *Oct 8 15:51:42.746: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=1, DigitBeginFlags=0x0,
Rtp Timestamp=0x47BB48, Rtp Expiration=0x0
004862: *Oct 8 15:51:42.746: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=1, Duration=100,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
004863: *Oct 8 15:51:42.746: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
004864: *Oct 8 15:51:42.866: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=7, DigitBeginFlags=0x0,
Rtp Timestamp=0x483848, Rtp Expiration=0x0
004865: *Oct 8 15:51:42.866: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=7, Duration=100,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
004866: *Oct 8 15:51:42.866: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
004867: *Oct 8 15:51:43.006: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=7, DigitBeginFlags=0x0,
Rtp Timestamp=0x48B548, Rtp Expiration=0x0
004868: *Oct 8 15:51:43.006: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=7, Duration=100,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
004869: *Oct 8 15:51:43.006: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
004870: *Oct 8 15:51:43.134: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=4, DigitBeginFlags=0x0,
Rtp Timestamp=0x493248, Rtp Expiration=0x0
004871: *Oct 8 15:51:43.134: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=4, Duration=100,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
004872: *Oct 8 15:51:43.134: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
004873: *Oct 8 15:51:43.254: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=7, DigitBeginFlags=0x0,
Rtp Timestamp=0x49AF48, Rtp Expiration=0x0
004874: *Oct 8 15:51:43.254: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=7, Duration=100,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
004875: *Oct 8 15:51:43.254: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
004876: *Oct 8 15:51:43.394: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=5, DigitBeginFlags=0x0,
Rtp Timestamp=0x4A2C48, Rtp Expiration=0x0
004877: *Oct 8 15:51:43.394: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=5, Duration=100,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
004878: *Oct 8 15:51:43.394: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
004879: *Oct 8 15:51:43.514: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=3, DigitBeginFlags=0x0,
Rtp Timestamp=0x4AA948, Rtp Expiration=0x0
004880: *Oct 8 15:51:43.514: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=3, Duration=100,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
004881: *Oct 8 15:51:43.514: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
004882: *Oct 8 15:51:43.634: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=5, DigitBeginFlags=0x0,
Rtp Timestamp=0x4B2648, Rtp Expiration=0x0
004883: *Oct 8 15:51:43.634: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=5, Duration=100,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
004884: *Oct 8 15:51:43.634: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
004885: *Oct 8 15:51:43.774: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=3, DigitBeginFlags=0x0,
Rtp Timestamp=0x4BA348, Rtp Expiration=0x0
004886: *Oct 8 15:51:43.774: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=321, Digit=3, Duration=100,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
004887: *Oct 8 15:51:43.774: //321/C78ACB3C80D4/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
004888: *Oct 8 15:51:53.774: //321/C78ACB3C80D4/CCAPI/cc_handle_inter_digit_timer:
Generate inter-digit timeout CC_EV_CALL_DIGIT_END event
004889: *Oct 8 15:51:53.774: //321/xxxxxxxxxxxx/CCAPI/ccCallReportDigits:
(callID=0x141, digit_event=0x0, enable=FALSE, consume=FALSE)
004890: *Oct 8 15:51:53.774: //321/C78ACB3C80D4/CCAPI/ccCallReportDigits:
Enabled=TRUE, Call Id=321
004891: *Oct 8 15:51:53.774: //321/xxxxxxxxxxxx/CCAPI/cc_api_call_report_digits_done:
(vdbPtr=0x67BC1158, callID=0x141, disp=0, digit_event=0x0, enable=FALSE, consume=FALSE)
004892: *Oct 8 15:51:53.774: //321/C78ACB3C80D4/CCAPI/cc_api_call_report_digits_done:
Enabled=TRUE, Disposition=0x0, Interface=0x67BC1158, Call Id=321
004893: *Oct 8 15:51:53.774: //321/C78ACB3C80D4/CCAPI/cc_api_call_report_digits_done:
Call Entry(Initial Digit Timeout=10000(ms), Inter Digit Timeout=10000(ms))
004894: *Oct 8 15:51:53.774: //321/C78ACB3C80D4/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
004895: *Oct 8 15:51:53.774: //321/C78ACB3C80D4/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=9, Params=0x6929033C, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
004896: *Oct 8 15:51:53.774: //321/C78ACB3C80D4/CCAPI/ccCheckClipClir:
In: Calling Number=6175559034(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
004897: *Oct 8 15:51:53.774: //321/C78ACB3C80D4/CCAPI/ccCheckClipClir:
Out: Calling Number=6175559034(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
004898: *Oct 8 15:51:53.774: //321/C78ACB3C80D4/CCAPI/ccCallSetupRequest:
Destination Pattern=.T, Called Number=150855543003, Digit Strip=FALSE
004899: *Oct 8 15:51:53.774: //321/C78ACB3C80D4/CCAPI/ccCallSetupRequest:
Calling Number=6175559034(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=150855543003(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=
Account Number=, Final Destination Flag=FALSE,
Guid=C78ACB3C-D22A-11DF-80D4-F61ABE3841C5, Outgoing Dial-peer=9
004900: *Oct 8 15:51:53.774: //321/C78ACB3C80D4/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=
----- ccCallInfo IE subfields -----
cisco-ani=6175559034
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=150855543003
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=0 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0
004901: *Oct 8 15:51:53.774: //321/C78ACB3C80D4/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0xC02B8C6C, Interface Type=3, Destination=, Mode=0x0,
Call Params(Calling Number=6175559034,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened,
Presentation=Allowed),
Called Number=150855543003(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=RegularLine, FinalDestinationFlag=FALSE, Outgoing Dial-peer=9, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
004902: *Oct 8 15:51:53.774: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
004903: *Oct 8 15:51:53.774: :cc_get_feature_vsa malloc success
004904: *Oct 8 15:51:53.774: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
004905: *Oct 8 15:51:53.774: cc_get_feature_vsa count is 2
004906: *Oct 8 15:51:53.774: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
004907: *Oct 8 15:51:53.774: :FEATURE_VSA attributes are:
feature_name:0,fearture_time:3225557536,feature_id:85
004908: *Oct 8 15:51:53.774: //322/C78ACB3C80D4/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1
004909: *Oct 8 15:51:53.774: //322/C78ACB3C80D4/CCAPI/ccCallSetContext:
Context=0x692902EC
004910: *Oct 8 15:51:53.774: //321/C78ACB3C80D4/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=9
004911: *Oct 8 15:51:53.774: //322/C78ACB3C80D4/CCAPI/cc_api_call_proceeding:
Interface=0xC02B8C6C, Progress Indication=NULL(0)
004912: *Oct 8 15:51:53.778: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:150855543003@198.102.22.150:5060 SIP/2.0
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK11C818
Remote-Party-ID: <6175559034>;party=calling;screen=no;privacy=off6175559034>
From: <6175559034>;tag=4B0ADF8-DB26175559034>
To: <150855543003>150855543003>
Date: Fri, 08 Oct 2010 15:51:53 GMT
Call-ID: CE676171-D22A11DF-80D9F61A-BE3841C5@24.11.70.246
Supported: timer,resource-priority,replaces
Require: 100rel
Min-SE: 1800
Cisco-Guid: 3347761980-3525972447-2161440282-3191357893
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: 1286553113
Contact: <6175559034>6175559034>
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 232
v=0
o=CiscoSystemsSIP-GW-UserAgent 203 6350 IN IP4 24.11.70.246
s=SIP Call
c=IN IP4 24.11.70.246
t=0 0
m=audio 17568 RTP/AVP 18 0
c=IN IP4 24.11.70.246
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=yes
a=rtpmap:0 PCMU/8000
004913: *Oct 8 15:51:54.430: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 100 Trying
From: <6175559034>;tag=4B0ADF8-DB26175559034>
To: <150855543003>;tag=961666c6-13c4-4caf4d68-7c52ddf1-16a7150855543003>
Call-ID: CE676171-D22A11DF-80D9F61A-BE3841C5@24.11.70.246
CSeq: 101 INVITE
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK11C818
Timestamp: 1286553113
Contact: <150855543003>150855543003>
Content-Length: 0
004914: *Oct 8 15:51:56.318: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 501 Not Implemented
From: <6175559034>;tag=4B0ADF8-DB26175559034>
To: <150855543003>;tag=961666c6-13c4-4caf4d68-7c52ddf1-16a7150855543003>
Call-ID: CE676171-D22A11DF-80D9F61A-BE3841C5@24.11.70.246
CSeq: 101 INVITE
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK11C818
Content-Length: 0
004915: *Oct 8 15:51:56.318: //322/C78ACB3C80D4/CCAPI/cc_api_call_disconnected:
Cause Value=79, Interface=0xC02B8C6C, Call Id=322
004916: *Oct 8 15:51:56.318: //322/C78ACB3C80D4/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=79, Retry Count=0)
004917: *Oct 8 15:51:56.318: //321/xxxxxxxxxxxx/CCAPI/ccCallReleaseResources:
release reserved xcoding resource.
004918: *Oct 8 15:51:56.318: //322/C78ACB3C80D4/CCAPI/ccCallSetAAA_Accounting:
Accounting=0, Call Id=322
004919: *Oct 8 15:51:56.318: //322/C78ACB3C80D4/CCAPI/ccCallDisconnect:
Cause Value=79, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=79)
004920: *Oct 8 15:51:56.318: //322/C78ACB3C80D4/CCAPI/ccCallDisconnect:
Cause Value=79, Call Entry(Responsed=TRUE, Cause Value=79)
004921: *Oct 8 15:51:56.322: //322/C78ACB3C80D4/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0xC02B8C6C, Tag=0x0, Call Id=322,
Call Entry(Disconnect Cause=79, Voice Class Cause Code=0, Retry Count=0)
004922: *Oct 8 15:51:56.322: //322/C78ACB3C80D4/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
004923: *Oct 8 15:51:56.322: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
004924: *Oct 8 15:51:56.322: :cc_free_feature_vsa freeing C0421A18
004925: *Oct 8 15:51:56.322: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
004926: *Oct 8 15:51:56.322: vsacount in free is 1
004927: *Oct 8 15:51:56.322: //321/C78ACB3C80D4/CCAPI/ccCallDisconnect:
Cause Value=79, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
004928: *Oct 8 15:51:56.322: //321/C78ACB3C80D4/CCAPI/ccCallDisconnect:
Cause Value=79, Call Entry(Responsed=TRUE, Cause Value=79)
004929: *Oct 8 15:51:56.322: //321/C78ACB3C80D4/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
004930: *Oct 8 15:51:56.322: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
ACK sip:150855543003@198.102.22.150:5060 SIP/2.0
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK11C818
From: <6175559034>;tag=4B0ADF8-DB26175559034>
To: <150855543003>;tag=961666c6-13c4-4caf4d68-7c52ddf1-16a7150855543003>
Date: Fri, 08 Oct 2010 15:51:53 GMT
Call-ID: CE676171-D22A11DF-80D9F61A-BE3841C5@24.11.70.246
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event
Content-Length: 0
004931: *Oct 8 15:51:56.710: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 501 Not Implemented
From: <6175559034>;tag=4B0ADF8-DB26175559034>
To: <150855543003>;tag=961666c6-13c4-4caf4d68-7c52ddf1-16a7150855543003>
Call-ID: CE676171-D22A11DF-80D9F61A-BE3841C5@24.11.70.246
CSeq: 101 INVITE
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK11C818
Content-Length: 0
004932: *Oct 8 15:51:56.710: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
ACK sip:150855543003@198.102.22.150:5060 SIP/2.0
Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK11C818
From: <6175559034>;tag=4B0ADF8-DB26175559034>
To: <150855543003>;tag=961666c6-13c4-4caf4d68-7c52ddf1-16a7150855543003>
Date: Fri, 08 Oct 2010 15:51:53 GMT
Call-ID: CE676171-D22A11DF-80D9F61A-BE3841C5@24.11.70.246
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event
Reason: Q.850;cause=79
Content-Length: 0
004933: *Oct 8 15:52:00.842: //321/C78ACB3C80D4/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x67BC1158, Tag=0x0, Call Id=321,
Call Entry(Disconnect Cause=79, Voice Class Cause Code=0, Retry Count=0)
004934: *Oct 8 15:52:00.842: //321/C78ACB3C80D4/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
004935: *Oct 8 15:52:00.842: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
004936: *Oct 8 15:52:00.842: :cc_free_feature_vsa freeing C0421CA0
004937: *Oct 8 15:52:00.842: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
004938: *Oct 8 15:52:00.842: vsacount in free is 0
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: