SIP Trunk on CME - Codec mismatch

Unanswered Question
Sep 6th, 2010
User Badges:

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

  • 1
  • 2
  • 3
  • 4
  • 5
Overall Rating: 5 (4 ratings)
Loading.
paolo bevilacqua Mon, 09/06/2010 - 07:58
User Badges:
  • Super Gold, 25000 points or more
  • Hall of Fame,

    Founding Member

If the call connects, unlikely is codec issue.


Do you have a firewall in between CME and SIP SP ?

Michael Murray Mon, 09/06/2010 - 08:02
User Badges:

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.

paolo bevilacqua Mon, 09/06/2010 - 08:08
User Badges:
  • Super Gold, 25000 points or more
  • Hall of Fame,

    Founding Member

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",

Michael Murray Tue, 09/07/2010 - 07:51
User Badges:

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.

Steven Holl Wed, 09/08/2010 - 07:23
User Badges:
  • Cisco Employee,

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.

Michael Murray Wed, 09/08/2010 - 18:53
User Badges:


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 [email protected]

*Aug 30 18:03:55.071: //71/C2E835E78047/SIP/Info/sipSPIUsetBillingProfile: sipCallId for billing records = [email protected]

*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:[email protected]:5060 SIP/2.0


Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E


Remote-Party-ID: ;party=calling;screen=no;privacy=off


From: ;tag=549C40-173C


To:


Date: Mon, 30 Aug 2010 18:03:55 GMT


Call-ID: [email protected]


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:


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:[email protected]:5060 SIP/2.0


Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E


Remote-Party-ID: ;party=calling;screen=no;privacy=off


From: ;tag=549C40-173C


To:


Date: Mon, 30 Aug 2010 18:03:55 GMT


Call-ID: [email protected]


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:


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:[email protected]:5060 SIP/2.0


Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E


Remote-Party-ID: ;party=calling;screen=no;privacy=off


From: ;tag=549C40-173C


To:


Date: Mon, 30 Aug 2010 18:03:56 GMT


Call-ID: [email protected]


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:


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: ;tag=549C40-173C


To: ;tag=961666c6-13c4-4c7c01c2-b3f42025-934


Call-ID: [email protected]


CSeq: 101 INVITE


Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E


Timestamp: 1283191435


Contact:


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: ;tag=549C40-173C


To: ;tag=961666c6-13c4-4c7c01c2-b3f42025-934


Call-ID: [email protected]


CSeq: 101 INVITE


Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E


Timestamp: 1283191435


Contact:


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: ;tag=549C40-173C


To: ;tag=961666c6-13c4-4c7c01c2-b3f42025-934


Call-ID: [email protected]


CSeq: 101 INVITE


Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E


Timestamp: 1283191435


Contact:


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: ;tag=549C40-173C


To: ;tag=961666c6-13c4-4c7c01c2-b3f42025-934


Call-ID: [email protected]


CSeq: 101 INVITE


Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E


Contact:


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: ;tag=549C40-173C


To: ;tag=961666c6-13c4-4c7c01c2-b3f42025-934


Call-ID: [email protected]


CSeq: 101 INVITE


Session-Expires: 1800;refresher=uac


Supported: timer


Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E


Contact:


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:[email protected]:5060 SIP/2.0


Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4322F3


From: ;tag=549C40-173C


To: ;tag=961666c6-13c4-4c7c01c2-b3f42025-934


Date: Mon, 30 Aug 2010 18:03:56 GMT


Call-ID: [email protected]


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:[email protected]:5060 SIP/2.0


Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK441389


From: ;tag=549C40-173C


To: ;tag=961666c6-13c4-4c7c01c2-b3f42025-934


Date: Mon, 30 Aug 2010 18:03:56 GMT


Call-ID: [email protected]


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: ;tag=549C40-173C


To: ;tag=961666c6-13c4-4c7c01c2-b3f42025-934


Call-ID: [email protected]


CSeq: 101 INVITE


Session-Expires: 1800;refresher=uac


Supported: timer


Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E


Contact:


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:[email protected]:5060 SIP/2.0


Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK441389


From: ;tag=549C40-173C


To: ;tag=961666c6-13c4-4c7c01c2-b3f42025-934


Date: Mon, 30 Aug 2010 18:03:56 GMT


Call-ID: [email protected]


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: ;tag=549C40-173C


To: ;tag=961666c6-13c4-4c7c01c2-b3f42025-934


Call-ID: [email protected]


CSeq: 101 INVITE


Session-Expires: 1800;refresher=uac


Supported: timer


Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK4222E


Contact:


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: ;tag=549C40-173C


To: ;tag=961666c6-13c4-4c7c01c2-b3f42025-934


Call-ID: [email protected]


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 [email protected]

*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: ;tag=549C40-173C


To: ;tag=961666c6-13c4-4c7c01c2-b3f42025-934


Call-ID: [email protected]


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#

Steven Holl Thu, 09/09/2010 - 06:30
User Badges:
  • Cisco Employee,

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.

Michael Murray Mon, 10/04/2010 - 07:13
User Badges:

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

Michael Murray Thu, 10/07/2010 - 13:21
User Badges:

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:[email protected]:5060 SIP/2.0

From: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

To:

Call-ID: [email protected]

CSeq: 1 INVITE

Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3090-77fa36b5-24f9

Max-Forwards: 70

Contact:

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


[email protected]

*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 =


[email protected]

*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


[email protected]

*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  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

To: ;tag=580B64-128D

Date: Thu, 07 Oct 2010 19:36:36 GMT

Call-ID: [email protected]

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  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

To: ;tag=580B64-128D

Date: Thu, 07 Oct 2010 19:36:36 GMT

Call-ID: [email protected]

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:

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:[email protected]:5060 SIP/2.0

From: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

To:

Call-ID: [email protected]

CSeq: 1 INVITE

Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3090-77fa36b5-24f9

Max-Forwards: 70

Contact:

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  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

To: ;tag=580B64-128D

Date: Thu, 07 Oct 2010 19:36:36 GMT

Call-ID: [email protected]

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:

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:[email protected]:5060 SIP/2.0

From: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

To:

Call-ID: [email protected]

CSeq: 1 INVITE

Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3090-77fa36b5-24f9

Max-Forwards: 70

Contact:

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  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

To: ;tag=580B64-128D

Date: Thu, 07 Oct 2010 19:36:37 GMT

Call-ID: [email protected]

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:

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  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

To: ;tag=580B64-128D

Date: Thu, 07 Oct 2010 19:36:37 GMT

Call-ID: [email protected]

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:

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  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

To: ;tag=580B64-128D

Date: Thu, 07 Oct 2010 19:36:37 GMT

Call-ID: [email protected]

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:

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:[email protected]:5060 SIP/2.0

From: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

To: ;tag=580B64-128D

Call-ID: [email protected]

CSeq: 1 ACK

Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3096-77fa4c12-2516

Max-Forwards: 70

Contact:

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:[email protected]:5060 SIP/2.0

Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK242A

From: ;tag=580B64-128D

To: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

Date: Thu, 07 Oct 2010 19:36:41 GMT

Call-ID: [email protected]

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:[email protected]:5060 SIP/2.0

Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK242A

From: ;tag=580B64-128D

To: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

Date: Thu, 07 Oct 2010 19:36:41 GMT

Call-ID: [email protected]

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:[email protected]:5060 SIP/2.0

From: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

To: ;tag=580B64-128D

Call-ID: [email protected]

CSeq: 1 ACK

Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae3096-77fa4c12-2516

Max-Forwards: 70

Contact:

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: ;tag=580B64-128D

To: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

Call-ID: [email protected]

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


[email protected]

*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


[email protected]

*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: ;tag=580B64-128D

To: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae3090-77fa36b5-4fc0

Call-ID: [email protected]

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

Michael Murray Thu, 10/07/2010 - 13:26
User Badges:

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                                                                           

Steven Holl Thu, 10/07/2010 - 15:19
User Badges:
  • Cisco Employee,

Follow SIP Call ID [email protected]


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.

Michael Murray Thu, 10/07/2010 - 15:36
User Badges:

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:[email protected]:5060 SIP/2.0

From: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

To:

Call-ID: [email protected]

CSeq: 1 INVITE

Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5262-787e53b1-4e20

Max-Forwards: 70

Contact:

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  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

To: ;tag=DC2810-B33

Date: Thu, 07 Oct 2010 22:00:54 GMT

Call-ID: [email protected]

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  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

To: ;tag=DC2810-B33

Date: Thu, 07 Oct 2010 22:00:54 GMT

Call-ID: [email protected]

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:

Content-Length: 0



002260: *Oct  7 22:00:54.611: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Received:

INVITE sip:[email protected]:5060 SIP/2.0

From: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

To:

Call-ID: [email protected]

CSeq: 1 INVITE

Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5262-787e53b1-4e20

Max-Forwards: 70

Contact:

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  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

To: ;tag=DC2810-B33

Date: Thu, 07 Oct 2010 22:00:54 GMT

Call-ID: [email protected]

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:

Content-Length: 0



002262: *Oct  7 22:00:55.419: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Received:

INVITE sip:[email protected]:5060 SIP/2.0

From: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

To:

Call-ID: [email protected]

CSeq: 1 INVITE

Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5262-787e53b1-4e20

Max-Forwards: 70

Contact:

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  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

To: ;tag=DC2810-B33

Date: Thu, 07 Oct 2010 22:00:55 GMT

Call-ID: [email protected]

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:

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  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

To: ;tag=DC2810-B33

Date: Thu, 07 Oct 2010 22:00:55 GMT

Call-ID: [email protected]

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:

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  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

To: ;tag=DC2810-B33

Date: Thu, 07 Oct 2010 22:00:55 GMT

Call-ID: [email protected]

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:

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:[email protected]:5060 SIP/2.0

From: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

To: ;tag=DC2810-B33

Call-ID: [email protected]

CSeq: 1 ACK

Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5265-787e5de2-6477

Max-Forwards: 70

Contact:

Content-Length: 0




002309: *Oct  7 22:00:56.831: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Sent:

BYE sip:[email protected]:5060 SIP/2.0

Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK58B15

From: ;tag=DC2810-B33

To: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

Date: Thu, 07 Oct 2010 22:00:56 GMT

Call-ID: [email protected]

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:[email protected]:5060 SIP/2.0

From: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

To: ;tag=DC2810-B33

Call-ID: [email protected]

CSeq: 1 ACK

Via: SIP/2.0/UDP 198.102.22.150:5060;rport;branch=z9hG4bK-4cae5265-787e5de2-6477

Max-Forwards: 70

Contact:

Content-Length: 0




002311: *Oct  7 22:00:57.331: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Sent:

BYE sip:[email protected]:5060 SIP/2.0

Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK58B15

From: ;tag=DC2810-B33

To: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

Date: Thu, 07 Oct 2010 22:00:57 GMT

Call-ID: [email protected]

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: ;tag=DC2810-B33

To: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

Call-ID: [email protected]

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: ;tag=DC2810-B33

To: "MASSACHUSETTS  ";tag=961666c6-13c4-4cae5262-787e53b1-5923

Call-ID: [email protected]

CSeq: 101 BYE

Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK58B15

Content-Length: 0                         

dksingh Thu, 10/07/2010 - 20:08
User Badges:
  • Cisco Employee,

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

Michael Murray Fri, 10/08/2010 - 09:11
User Badges:

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:[email protected]:5060 SIP/2.0

Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK11C818

Remote-Party-ID: ;party=calling;screen=no;privacy=off

From: ;tag=4B0ADF8-DB2

To:

Date: Fri, 08 Oct 2010 15:51:53 GMT

Call-ID: [email protected]

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:

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: ;tag=4B0ADF8-DB2

To: ;tag=961666c6-13c4-4caf4d68-7c52ddf1-16a7

Call-ID: [email protected]

CSeq: 101 INVITE

Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK11C818

Timestamp: 1286553113

Contact:

Content-Length: 0

004914: *Oct  8 15:51:56.318: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 501 Not Implemented

From: ;tag=4B0ADF8-DB2

To: ;tag=961666c6-13c4-4caf4d68-7c52ddf1-16a7

Call-ID: [email protected]

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:[email protected]:5060 SIP/2.0

Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK11C818

From: ;tag=4B0ADF8-DB2

To: ;tag=961666c6-13c4-4caf4d68-7c52ddf1-16a7

Date: Fri, 08 Oct 2010 15:51:53 GMT

Call-ID: [email protected]

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: ;tag=4B0ADF8-DB2

To: ;tag=961666c6-13c4-4caf4d68-7c52ddf1-16a7

Call-ID: [email protected]

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:[email protected]:5060 SIP/2.0

Via: SIP/2.0/UDP 24.11.70.246:5060;branch=z9hG4bK11C818

From: ;tag=4B0ADF8-DB2

To: ;tag=961666c6-13c4-4caf4d68-7c52ddf1-16a7

Date: Fri, 08 Oct 2010 15:51:53 GMT

Call-ID: [email protected]

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        

Michael Murray Fri, 10/08/2010 - 09:50
User Badges:


Wanted to post the latest config as changes have been made during the troubleshooting process.


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

  rel1xx require "100rel"

!

!

voice class codec 1

codec preference 1 g729r8

codec preference 2 g729br8

codec preference 3 g711ulaw

!

!

!

!

!

!

!

!

!

!

!

voice iec syslog

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

!

!

!

!

!

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

voice-class sip dtmf-relay force rtp-nte

session protocol sipv2

session target ipv4:198.102.22.150

no vad

!

dial-peer voice 10 voip

session protocol sipv2

incoming called-number .

dtmf-relay rtp-nte

no vad

!

!

sip-ua

timers trying 1000

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

!

!

Steven Holl Fri, 10/08/2010 - 14:01
User Badges:
  • Cisco Employee,

Maybe see about switching transport for SIP to TCP on each end?  That may help with message acknowledgement across this link, perhaps?

Actions

This Discussion