Re: Ringback over SIP lines (CUCMv7.1.5 --> 2811 --> SIP Provide

gcrawford2005 · ‎10-10-2012

Problem:

1. Ringback is not working on any phones going out my SIP gateway (2811 --> my SIP provider).

I have tried fast start for incoming/outgoing and enabled MTP, but then my DTMF stops working and I still don't have a ringback. Below are the details on my setup. If you have any input on how I should be doing things, feel free to toss it in.

2. I have a DSP in the 2811, but don't think I have anything to use it currently. How can i configure it to be used locally for whatever the 2811/SIP partner could need it for. I already have 2 MTP's configured on both CMs.

Hardware

--------------

2x CUCM v7.1.5.34900-7

1x Cisco 2811 w/ 1x PVDM2-16 & c2800nm-advipservicesk9-mz.124-22.T.bin

Cisco 2811 Config (Voice Related Parts)

----------------------------------------------------------

voice service voip

allow-connections h323 to sip

allow-connections sip to h323

allow-connections sip to sip

no supplementary-service sip moved-temporarily

no supplementary-service sip refer

h323

sip

voice class codec 1

codec preference 1 g711ulaw

codec preference 2 g711alaw

voice class h323 1

h225 timeout tcp establish 2

h225 timeout call-proceeding 1

h225 timeout setup 3

call start fast

telephony-service ccm-compatible

ccm-compatible

voice-card 0

dsp services dspfarm

ccm-manager fax protocol cisco

mgcp fax t38 ecm

dial-peer voice 1 voip

description This is for outgoing calls through the SIP...

destination-pattern .T

voice-class codec 1

session protocol sipv2

session target sip-server

session transport udp

incoming called-number 9T

dtmf-relay rtp-nte

sip-ua

credentials username **** password 7 **** realm asterisk

authentication username **** password 7 **** realm asterisk

no remote-party-id

retry invite 2

retry register 2

registrar dns:**** expires 3600

sip-server dns:****

host-registrar

Suresh Subramanian · ‎10-11-2012

Hi, could you please provide the "debug ccsip all" output? check what you receive 180(w/sdp or wo/sdp) or 183 from the provider? if you receive 180 without SDP, then make sure the MRGL assigned to the SIP Trunk has ANN to generate the ringback locally. if you receive 183 and/or 180 with SDP, then provider will generate the ringback.

//Suresh Please rate all the useful posts.

gcrawford2005 · ‎10-11-2012

Below is the output of a call I made to an 858 number. I didn't see what you were talking about on the SDP.

As a side note, I have seen some people say they configure the Cisco 2811 as a SIP gateway rather than H323. Is there pros or cons to doing this?

I talked to our SIP provider and they recommend configuring our equipment to accept 183...

"accept 183, instead of generating ringing locally on outbound calls, because there are a number of companies (Microsoft, Intel, Metlife are ones I\'ve seen) that start their IVRs in 183."

===================================

*Oct 11 15:37:42.676: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x492CE530) with key=[898] to table

*Oct 11 15:37:42.676: //905/000000000000/SIP/State/sipSPIChangeState: 0x492CE530 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)

*Oct 11 15:37:42.676: //905/000000000000/SIP/Info/ccsip_call_setup_request: Before processing SETUP REQccb->pld.flags_ipip = 200

*Oct 11 15:37:42.676: //905/000000000000/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-H323

*Oct 11 15:37:42.676: //905/000000000000/SIP/Info/ccsip_call_setup_request:

This a IPIP call: NULL peer_channel - peer_channels = 0x0, peer_param = 0x4964CA18, callID= 905, peer_callID = 904

*Oct 11 15:37:42.676: //905/000000000000/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-H323

*Oct 11 15:37:42.676: //905/000000000000/SIP/Info/ccsip_call_setup_request: After processing SETUP REQccb->pld.flags_ipip = 200000

*Oct 11 15:37:42.676: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : sip24.sip-me.net target_port : 5060

*Oct 11 15:37:42.676: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_SETUP

*Oct 11 15:37:42.680: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 2

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 389 to table

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Info/sipSPIGetCallConfig: preferred_codec set[0] type :No Codec bytes: 0

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Media/sipSPICopyPeerDataToCCB: Firewall traversal is not enabled

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Info/sipSPIGetCallConfig: xcoder high-density disabled

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Info/sipSPIGetCallConfig: Flow Mode set to FLOW_THROUGH

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Info/preprocessSetup:

This is a not a SIGO Call -, could be DM call

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Info/sipSPI_ipip_call_setup: No video caps posted by peer

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Info/sipSPI_ipip_call_setup: xcoder high-density disabled

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Info/sipSPI_ipip_call_setup: Flow Mode set to FLOW_THROUGH

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:

callid 905, channels 0x0 caps 0x0

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Info/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Info/sipSPIAddMLPPServicesInfo: No MLP Info available on incoming leg

*Oct 11 15:37:42.680: //905/80BB30990800/SIP/Info/sipSPIAddCiscoGcid: Gcid value not set - not adding header.

*Oct 11 15:37:42.684: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddPrivacyandIdentityInfo: ccb->local_host_name,ccb->src_addr_str is NULL

*Oct 11 15:37:42.684: //905/80BB30990800/SIP/Error/sipSPI_ipip_set_history_info_header: Not SIP2SIP mode

*Oct 11 15:37:42.684: //905/80BB30990800/SIP/Info/act_idle_continue_call_setup:

*Oct 11 15:37:42.684: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_DNS_RESOLVE

*Oct 11 15:37:42.684: //905/80BB30990800/SIP/State/sipSPIChangeState: 0x492CE530 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_SENT_DNS)

*Oct 11 15:37:42.684: //905/80BB30990800/SIP/State/sipSPIChangeState: 0x492CE530 : State change from (STATE_IDLE, SUBSTATE_SENT_DNS) to (STATE_IDLE, SUBSTATE_SENT_DNS)

*Oct 11 15:37:42.684: //905/80BB30990800/SIP/Info/sipSPIUaddCcbToUACTable: ****Adding to UAC table.

*Oct 11 15:37:42.684: //905/80BB30990800/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x492CE530 key=6E51CFEA-12F011E2-8017B7AB-F260055A@10.0.101.9

*Oct 11 15:37:42.684: //905/80BB30990800/SIP/Info/sipSPIUsetBillingProfile: sipCallId for billing records = 6E51CFEA-12F011E2-8017B7AB-F260055A@10.0.101.9

*Oct 11 15:37:42.684: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: TYPE SRV query for _sip._udp.sip24.sip-me.net and type:1

*Oct 11 15:37:42.692: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_aaaa_query: DNS query for sip24.sip-me.net and type:1

*Oct 11 15:37:42.692: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_query: TYPE A query successful for sip24.sip-me.net

*Oct 11 15:37:42.692: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_aaaa_query: IP Address of sip24.sip-me.net is:

*Oct 11 15:37:42.692: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_aaaa_query: 69.121.96.12

*Oct 11 15:37:42.692: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 43

*Oct 11 15:37:42.692: //905/80BB30990800/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0

*Oct 11 15:37:42.692: //905/80BB30990800/SIP/Error/sipSPI_ipip_set_history_info_header: Not SIP2SIP mode

*Oct 11 15:37:42.692: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 69.121.96.12,Port 5060, Transport 1, SentBy Port 5060

*Oct 11 15:37:42.692: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT

*Oct 11 15:37:42.692: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIgetRegistrarHost: registrar host retrieved : sip24.sip-me.net

*Oct 11 15:37:42.696: //905/80BB30990800/SIP/Info/sipSPISendInvite: Associated container=0x4964C948 to Invite

*Oct 11 15:37:42.696: //905/80BB30990800/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer

*Oct 11 15:37:42.696: //905/80BB30990800/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE

*Oct 11 15:37:42.696: //905/80BB30990800/SIP/Transport/sipSPITransportSendMessage: msg=0x483963C0, addr=69.121.96.12, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x416E22E4

*Oct 11 15:37:42.696: //905/80BB30990800/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

*Oct 11 15:37:42.696: //905/80BB30990800/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0

*Oct 11 15:37:42.696: //905/80BB30990800/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x483963C0

*Oct 11 15:37:42.696: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x483963C0, addr=69.121.96.12, port=5060, connId=2 for UDP

*Oct 11 15:37:42.696: //905/80BB30990800/SIP/Info/sentInviteRequest: Sent Invite in state STATE_IDLE

*Oct 11 15:37:42.696: //-1/xxxxxxxxxxxx/SIP/Info/sentInviteRequest: Transaction active. Facilities will be queued.

*Oct 11 15:37:42.696: //905/80BB30990800/SIP/State/sipSPIChangeState: 0x492CE530 : State change from (STATE_IDLE, SUBSTATE_SENT_DNS) to (STATE_SENT_INVITE, SUBSTATE_NONE)

*Oct 11 15:37:42.696: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Sent:

INVITE sip:8586182100@sip24.sip-me.net:5060 SIP/2.0

Date: Thu, 11 Oct 2012 15:37:42 GMT

Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER

From: <>8586181234@sip24.sip-me.net>;tag=3312828-C6

Allow-Events: telephone-event

Supported: 100rel,timer,resource-priority,replaces,sdp-anat

Min-SE: 1800

Cisco-Guid: 2159751321-484860167-134221826-167863753

Timestamp: 1349969862

Content-Length: 0

User-Agent: Cisco-SIPGateway/IOS-12.x

To: <>8586182100@sip24.sip-me.net>

Contact: <8586181234>

Expires: 180

Call-ID: 6E51CFEA-12F011E2-8017B7AB-F260055A@10.0.101.9

Via: SIP/2.0/UDP 10.0.101.9:5060;branch=z9hG4bK70B2639

CSeq: 101 INVITE

Max-Forwards: 70

*Oct 11 15:37:42.724: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [69.121.96.12]:5060

*Oct 11 15:37:42.724: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1

*Oct 11 15:37:42.724: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x4875B174

*Oct 11 15:37:42.724: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x4875B174, addr=69.121.96.12, port=5060, connid=2, transport=UDP

*Oct 11 15:37:42.724: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog

*Oct 11 15:37:42.724: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 407 Proxy Authentication Required

Via: SIP/2.0/UDP 10.0.101.9:5060;branch=z9hG4bK70B2639;received=121.1.2.9

From: <>8586181234@sip24.sip-me.net>;tag=3312828-C6

To: <>8586182100@sip24.sip-me.net>;tag=as5af3ebaf

Call-ID: 6E51CFEA-12F011E2-8017B7AB-F260055A@10.0.101.9

CSeq: 101 INVITE

User-Agent: packetrino

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO

Supported: replaces

Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="59e96ccd"

Content-Length: 0

*Oct 11 15:37:42.728: //905/80BB30990800/SIP/Transport/sipSPISendAck: Sending ACK to the transport layer

*Oct 11 15:37:42.728: //905/80BB30990800/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE

*Oct 11 15:37:42.728: //905/80BB30990800/SIP/Transport/sipSPITransportSendMessage: msg=0x4961E570, addr=69.121.96.12, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x00000000

*Oct 11 15:37:42.728: //905/80BB30990800/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

*Oct 11 15:37:42.728: //905/80BB30990800/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0

*Oct 11 15:37:42.728: //905/80BB30990800/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x4961E570

*Oct 11 15:37:42.728: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x4961E570, addr=69.121.96.12, port=5060, connId=2 for UDP

*Oct 11 15:37:42.728: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container

*Oct 11 15:37:42.728: //905/80BB30990800/SIP/Info/sipSPIGenerateAuthorizationResponse: HA1 is: 8d3e23df7b2e2b39752fe99a2e41073b

*Oct 11 15:37:42.728: //905/80BB30990800/SIP/State/sipSPIChangeState: 0x492CE530 : State change from (STATE_SENT_INVITE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)

*Oct 11 15:37:42.728: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT

*Oct 11 15:37:42.728: //905/80BB30990800/SIP/Info/sipSPISendInvite: Associated container=0x4964C948 to Invite

*Oct 11 15:37:42.728: //905/80BB30990800/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer

*Oct 11 15:37:42.728: //905/80BB30990800/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE

*Oct 11 15:37:42.732: //905/80BB30990800/SIP/Transport/sipSPITransportSendMessage: msg=0x483963C0, addr=69.121.96.12, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x416E22E4

*Oct 11 15:37:42.732: //905/80BB30990800/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

*Oct 11 15:37:42.732: //905/80BB30990800/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0

*Oct 11 15:37:42.732: //905/80BB30990800/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x483963C0

*Oct 11 15:37:42.732: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x483963C0, addr=69.121.96.12, port=5060, connId=2 for UDP

*Oct 11 15:37:42.732: //905/80BB30990800/SIP/Info/sentInviteRequest: Sent Invite in state STATE_IDLE

*Oct 11 15:37:42.732: //-1/xxxxxxxxxxxx/SIP/Info/sentInviteRequest: Transaction active. Facilities will be queued.

*Oct 11 15:37:42.732: //905/80BB30990800/SIP/State/sipSPIChangeState: 0x492CE530 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_SENT_INVITE, SUBSTATE_NONE)

*Oct 11 15:37:42.732: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Sent:

ACK sip:8586182100@sip24.sip-me.net:5060 SIP/2.0

Date: Thu, 11 Oct 2012 15:37:42 GMT

From: <>8586181234@sip24.sip-me.net>;tag=3312828-C6

Allow-Events: telephone-event

Content-Length: 0

To: <>8586182100@sip24.sip-me.net>;tag=as5af3ebaf

Call-ID: 6E51CFEA-12F011E2-8017B7AB-F260055A@10.0.101.9

Via: SIP/2.0/UDP 10.0.101.9:5060;branch=z9hG4bK70B2639

CSeq: 101 ACK

Max-Forwards: 70

*Oct 11 15:37:42.732: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Sent:

INVITE sip:8586182100@sip24.sip-me.net:5060 SIP/2.0

Date: Thu, 11 Oct 2012 15:37:42 GMT

Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER

From: <>8586181234@sip24.sip-me.net>;tag=3312828-C6

Allow-Events: telephone-event

Supported: 100rel,timer,resource-priority,replaces,sdp-anat

Min-SE: 1800

Cisco-Guid: 2159751321-484860167-134221826-167863753

Timestamp: 1349969862

Content-Length: 0

User-Agent: Cisco-SIPGateway/IOS-12.x

Proxy-Authorization: Digest username="user_name",realm="asterisk",uri="sip:8586182100@sip24.sip-me.net:5060",response="cafa42a4d6152996172a85329c2e36c1",nonce="59e96ccd",algorithm=MD5

To: <>8586182100@sip24.sip-me.net>

Contact: <8586181234>

Expires: 180

Call-ID: 6E51CFEA-12F011E2-8017B7AB-F260055A@10.0.101.9

Via: SIP/2.0/UDP 10.0.101.9:5060;branch=z9hG4bK70CF22

CSeq: 102 INVITE

Max-Forwards: 70

*Oct 11 15:37:42.760: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [69.121.96.12]:5060

*Oct 11 15:37:42.760: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1

*Oct 11 15:37:42.760: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x4875B174

*Oct 11 15:37:42.760: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x4875B174, addr=69.121.96.12, port=5060, connid=2, transport=UDP

*Oct 11 15:37:42.760: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog

*Oct 11 15:37:42.760: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 100 Trying

Via: SIP/2.0/UDP 10.0.101.9:5060;branch=z9hG4bK70CF22;received=121.1.2.9

From: <>8586181234@sip24.sip-me.net>;tag=3312828-C6

To: <>8586182100@sip24.sip-me.net>

Call-ID: 6E51CFEA-12F011E2-8017B7AB-F260055A@10.0.101.9

CSeq: 102 INVITE

User-Agent: packetrino

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO

Supported: replaces

Contact: <8586182100>

Content-Length: 0

*Oct 11 15:37:42.760: //905/80BB30990800/SIP/State/sipSPIChangeState: 0x492CE530 : State change from (STATE_SENT_INVITE, SUBSTATE_NONE) to (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING)

*Oct 11 15:37:45.068: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [69.121.96.12]:5060

*Oct 11 15:37:45.068: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1

*Oct 11 15:37:45.068: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x4875B174

*Oct 11 15:37:45.068: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x4875B174, addr=69.121.96.12, port=5060, connid=2, transport=UDP

*Oct 11 15:37:45.068: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog

*Oct 11 15:37:45.068: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 183 Session Progress

Via: SIP/2.0/UDP 10.0.101.9:5060;branch=z9hG4bK70CF22;received=121.1.2.9

From: <>8586181234@sip24.sip-me.net>;tag=3312828-C6

To: <>8586182100@sip24.sip-me.net>;tag=as104fbfbe

Call-ID: 6E51CFEA-12F011E2-8017B7AB-F260055A@10.0.101.9

CSeq: 102 INVITE

User-Agent: packetrino

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO

Supported: replaces

Contact: <8586182100>

Content-Type: application/sdp

Content-Length: 334

v=0

o=root 1763 1763 IN IP4 69.121.96.12

s=session

c=IN IP4 69.121.96.12

t=0 0

m=audio 14774 RTP/AVP 0 8 3 18 101

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:3 GSM/8000

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=silenceSupp:off - - - -

a=ptime:20

a=sendrecv

*Oct 11 15:37:45.072: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container

*Oct 11 15:37:45.072: //905/80BB30990800/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1

SIP: Attribute mid, level 1 instance 1 not found.

*Oct 11 15:37:45.072: //905/80BB30990800/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.0.101.9

*Oct 11 15:37:45.072: //905/80BB30990800/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711ulaw) Negotiation Successful on Static Payload for m-line 1

*Oct 11 15:37:45.072: //905/80BB30990800/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20

*Oct 11 15:37:45.072: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711ulaw ptime :20, codecbytes: 160

*Oct 11 15:37:45.072: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20

*Oct 11 15:37:45.072: //905/80BB30990800/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711ulaw

*Oct 11 15:37:45.072: //905/80BB30990800/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1

*Oct 11 15:37:45.072: //905/80BB30990800/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved.

*Oct 11 15:37:45.072: //905/80BB30990800/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option

*Oct 11 15:37:45.072: //905/80BB30990800/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of full named event(NE) match in fmtp list of events.

*Oct 11 15:37:45.072: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0

*Oct 11 15:37:45.072: //905/80BB30990800/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay

*Oct 11 15:37:45.072: //905/80BB30990800/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 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1

payload_type=0, codec_bytes=160, codec=g711ulaw, dtmf_relay=rtp-nte

stream_type=voice+dtmf (1), dest_ip_address=69.121.96.12, dest_port=14774

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING)

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Media/sipSPIUpdCallWithSdpInfo:

Preferred Codec : g711ulaw, bytes :160

Preferred DTMF relay : rtp-nte

Preferred NTE payload : 101

Early Media : No

Delayed Media : Yes

Bridge Done : No

New Media : No

DSP DNLD Reqd : No

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.0.101.9

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_report_media_to_peer:

callId 905 peer 904 flags 0x200001 state STATE_RECD_PROCEEDING

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

CallID 905, sdp 0x497C12C0 channels 0x492CF7A4

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/copy_channels:

callId 905 size 0 ptr 0x48EB9F64)

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Hndl ptype 0 mline 1

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711ulaw

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 5

*Oct 11 15:37:45.076: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=20,stream->negotiated_codec_bytes=160, coverted ptime=20 stream->mline_index=1, media_ndx=1

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Adding codec 5 ptype 0 time 20, bytes 160 as channel 0 mline 1 ss 0 69.121.96.12:14774

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Hndl ptype 8 mline 1

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711alaw

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 6

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation NOT done, get ptime from sdp: ptime=20, media_ndx=1

*Oct 11 15:37:45.076: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711alaw ptime :20, codecbytes: 160

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Adding codec 6 ptype 8 time 20, bytes 160 as channel 1 mline 1 ss 0 69.121.96.12:14774

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Hndl ptype 3 mline 1

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec gsmfr

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Hndl ptype 18 mline 1

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Media/sipSPISelectCodecVersion: Codec (g729r8) is not in preferred list

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: An exact codec match not configured, using interoperable codec g729r8 pre-ietf

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g729r8 pre-ietf

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Hndl ptype 101 mline 1

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: setting ipip_caps DTMF to RFC2833: callid = 905, dtmf = 6

*Oct 11 15:37:45.076: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 5

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 6

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Info/sipSPI_ipip_report_media_to_peer:

callId 905 flags 0x100 state STATE_RECD_PROCEEDING

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Info/sipSPI_ipip_report_media_to_peer:

Report initial call media

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=-1, current_seq_num=0x2656

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=-1, current_seq_num=0x0

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Info/ccsip_do_caps_ind: Load DSP with codec: g711ulaw, Bytes=160

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Media/sipSPISetStreamInfo: 0 Active Streams

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Media/sipSPISetStreamInfo: Number of active streams is zero (0)!

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Media/sipSPISetStreamInfo:

caps.stream_count=0,caps.stream[0].stream_type=0xFFFF, caps.stream_list.xmitFunc=

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Media/sipSPISetStreamInfo: ??unknown??, caps.stream_list.context=

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Media/sipSPISetStreamInfo: 0x0 (gccb)

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_NTE_AND_OOB with rx payload = 101, tx payload = 101

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Info/sip_set_modem_caps: Disabling Modem Relay...

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled

*Oct 11 15:37:45.080: //905/80BB30990800/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 11 15:37:45.080: //905/80BB30990800/SIP/Info/ccsip_update_srtp_caps: 4754: Posting Remote SRTP caps to other callleg.

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Media/sipSPIUpdCallWithSdpInfo:

Stream type : voice+dtmf

Media line : 1

State : STREAM_ADDING (2)

Stream address type : 1

Callid : -1

Negotiated Codec : g711ulaw, bytes :160

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

Negotiated DTMF relay : rtp-nte

Negotiated NTE payload : 101 (tx), 101 (rx)

Negotiated CN payload : 0

Media Srce Addr/Port : [10.0.101.9]:0

Media Dest Addr/Port : [69.121.96.12]:14774

*Oct 11 15:37:45.080: //905/80BB30990800/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container

*Oct 11 15:37:45.080: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container

*Oct 11 15:37:45.080: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container

*Oct 11 15:37:45.084: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message

*Oct 11 15:37:45.084: //905/80BB30990800/SIP/Info/HandleSIP1xxSessionProgress: ccsip_api_call_cut_progress returned: SIP_SUCCESS

*Oct 11 15:37:45.084: //905/80BB30990800/SIP/State/sipSPIChangeState: 0x492CE530 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) to (STATE_RECD_PROCEEDING, SUBSTATE_NONE)

*Oct 11 15:37:45.084: //905/80BB30990800/SIP/Info/HandleSIP1xxSessionProgress: Transaction Complete. Lock on Facilities released.

*Oct 11 15:37:45.084: //905/80BB30990800/SIP/Info/ccsip_bridge: confID = 7, srcCallID = 905, dstCallID = 904

*Oct 11 15:37:45.084: //905/80BB30990800/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: -1/-1, new src/dest ccCallids: 905/904

*Oct 11 15:37:45.084: //905/80BB30990800/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=-1, new streamcallid=905

*Oct 11 15:37:45.088: //905/80BB30990800/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-H323

*Oct 11 15:37:45.088: //905/80BB30990800/SIP/Info/ccsip_bridge: xcoder_attached = 0, xmitFunc = 1126144576, ccb xmitFunc = 1126144576

*Oct 11 15:37:45.088: //905/80BB30990800/SIP/Info/ccsip_bridge: ccsip_bridge: Delayed Media case

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Info/ccsip_caps_ind: Entry

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=905, current_seq_num=0x0

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=905, current_seq_num=0x0

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Info/ccsip_caps_ind: Load DSP with negotiated codec: g711ulaw, Bytes=160

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Info/ccsip_caps_ind: Set forking flag to 0x0

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_NTE_AND_OOB with rx payload = 101, tx payload = 101

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Info/sip_set_modem_caps: Disabling Modem Relay...

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled

*Oct 11 15:37:45.108: //905/80BB30990800/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 11 15:37:45.108: //905/80BB30990800/SIP/Media/sipSPISetStreamInfo: 0 Active Streams

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Media/sipSPISetStreamInfo: Number of active streams is zero (0)!

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Media/sipSPISetStreamInfo:

caps.stream_count=0,caps.stream[0].stream_type=0xFFFF, caps.stream_list.xmitFunc=

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Media/sipSPISetStreamInfo: ??unknown??, caps.stream_list.context=

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Media/sipSPISetStreamInfo: 0x0 (gccb)

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Info/ccsip_caps_ind: Load DSP with codec : g711ulaw, Bytes=160, payload = 0

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Info/ccsip_caps_ind: ccsip_caps_ind: ccb->pld.flags_ipip = 0x200401

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Info/ccsip_caps_ind: No video caps detected in the caps posted by peer leg

*Oct 11 15:37:45.108: //905/80BB30990800/SIP/Info/ccsip_caps_ind: Setting CAPS_RECEIVED flag

*Oct 11 15:37:45.112: //905/80BB30990800/SIP/Info/ccsip_caps_ack: Set forking flag to 0x0

*Oct 11 15:37:45.116: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler:

*Oct 11 15:37:45.116: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 153)

*Oct 11 15:37:45.116: //905/80BB30990800/SIP/Info/ccsip_event_handler:

ccsip_event_handler: peer ID 904 chans 0x497C42D4 event 153 flags 0xC06018 0x100 0x200421 data 0x497C42D4

*Oct 11 15:37:45.116: //905/80BB30990800/SIP/Info/ccsip_event_handler:

ccsip_event_handler: CC_EV_H245_OPEN_CHANNEL_IND: peer ID 904 chans 0x497C42D4 event 153 flags 0xC06018 0x100 0x200421 data 0x497C42D4

*Oct 11 15:37:45.116: //905/80BB30990800/SIP/Info/sipSPI_ipip_send_channel_ind_with_symmetry:

CCSIP: Sending OPEN_CHANNEL_IND

with codec g711ulaw AND OPEN_CHANNEL_ACK

*Oct 11 15:37:45.116: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED

*Oct 11 15:37:45.220: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler:

*Oct 11 15:37:45.220: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 154)

*Oct 11 15:37:45.220: //905/80BB30990800/SIP/Info/ccsip_event_handler:

ccsip_event_handler: peer ID 904 chans 0x49768E0C event 154 flags 0xC06018 0x100 0x200421 data 0x49768E0C

*Oct 11 15:37:45.220: //905/80BB30990800/SIP/Info/ccsip_event_handler:

ccsip_event_handler: CC_EV_H245_OPEN_CHANNEL_ACK: peer ID 904 chans 0x49768E0C event 154 flags 0xC06018 0x100 0x200421 data 0x49768E0C

*Oct 11 15:37:45.224: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_NEW_MEDIA

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/ccsip_event_handler:

ccsip_event_handler: set event->type =

SIPSPI_EV_CC_NEW_MEDIA for CC_EV_H245_OPEN_CHANNEL_ACK!: peer ID 904 chans 0x49768E0C event 154 flags 0xC06018 0x100 0x200421 data 0x49768E0C

*Oct 11 15:37:45.224: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED

*Oct 11 15:37:45.224: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 26

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/sipSPI_ipip_handle_channel_info:

CCSIP:callID 905 ft: 1, inc 0, 10.1.101.201:20882, codec 5

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/sipSPI_ipip_handle_channel_info:

CCSIP:callid 905 state STATE_RECD_PROCEEDING

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:

callid 905, channels 0x49768E0C caps 0x497C75D8

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: Peer cap provided: callid = 905, peer dtmf = 0

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: callid = 905, peer not doing RFC2833, peer dtmf = 0, enable NTE_ASSUMED

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: callid = 905, this leg negotiated dtmf = 6, peer dtmf = 0, nte/oob DTMF_IWF enabled.

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:

nego mline 1 dtmf 0 ss 0 ret 12

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: CCB->pld.flags_ipip 0x203421

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: channel_ind/ack payload type 0

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:

retreive codec 5 ptype 0 time 20 bytes 160

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:

stream negotiated codec retreive codec 5

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/sipSPI_ipip_handle_channel_info: audio channel_ind

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Media/sipSPIProcessRtpSessions: sipSPIProcessRtpSessions

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 905) to the VOIP RTP library

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Media/sipSPIAddStream: Reserved port 16798 for rtp/rtcp

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.0.101.9

*Oct 11 15:37:45.224: //905/80BB30990800/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1

*Oct 11 15:37:45.228: //905/80BB30990800/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info

laddr = 10.0.101.9, lport = 16798, raddr = 69.121.96.12, rport=14774, do_rtcp=TRUE

src_callid = 905, dest_callid = 904, stream type = voice+dtmf, stream direction = SENDRECV

media_ip_addr = 69.121.96.12, vrf tableid = 0 media_addr_type = 1

*Oct 11 15:37:45.228: //905/80BB30990800/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one

*Oct 11 15:37:45.228: //905/80BB30990800/SIP/Info/sipSPICreateRtpSession: sess: 48802D08 do_rtcp:1

*Oct 11 15:37:45.228: //905/80BB30990800/SIP/Media/sipSPICreateRtpSession: stun is disabled

*Oct 11 15:37:45.228: //905/80BB30990800/SIP/Info/sipSPIUpdateRtcpSession:

DTMF inb/oob iwf enabled 101

*Oct 11 15:37:45.228: //905/80BB30990800/SIP/Media/sipSPIGetNewLocalMediaDirection:

New Remote Media Direction = SENDRECV

Present Local Media Direction = SENDRECV

New Local Media Direction = SENDRECV

retVal = 0

*Oct 11 15:37:45.228: //905/80BB30990800/SIP/State/sipSPIChangeStreamState: Stream (callid = 905) State changed from (STREAM_ADDING) to (STREAM_ACTIVE)

*Oct 11 15:37:45.228: //905/80BB30990800/SIP/Info/sipSPIUpdateSrcSdpFixedPart: RTP port already reserved for stream 1, src_port=16798

*Oct 11 15:37:45.228: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1

*Oct 11 15:37:45.228: //905/80BB30990800/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 16798

*Oct 11 15:37:45.228: //905/80BB30990800/SIP/Info/sipSPIUpdateSrcSdpVariablePart:

SIP update src sdp, negoitated codec 5, payload type 0

*Oct 11 15:37:45.228: //905/80BB30990800/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Negotiated method of dtmf relayand pyld: 6 101

*Oct 11 15:37:47.192: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [69.121.96.12]:5060

*Oct 11 15:37:47.192: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1

*Oct 11 15:37:47.192: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x4875B174

*Oct 11 15:37:47.196: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x4875B174, addr=69.121.96.12, port=5060, connid=2, transport=UDP

*Oct 11 15:37:47.196: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog

*Oct 11 15:37:47.196: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 200 OK

Via: SIP/2.0/UDP 10.0.101.9:5060;branch=z9hG4bK70CF22;received=121.1.2.9

From: <>8586181234@sip24.sip-me.net>;tag=3312828-C6

To: <>8586182100@sip24.sip-me.net>;tag=as104fbfbe

Call-ID: 6E51CFEA-12F011E2-8017B7AB-F260055A@10.0.101.9

CSeq: 102 INVITE

User-Agent: packetrino

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO

Supported: replaces

Contact: <8586182100>

Content-Type: application/sdp

Content-Length: 334

v=0

o=root 1763 1764 IN IP4 69.121.96.12

s=session

c=IN IP4 69.121.96.12

t=0 0

m=audio 14774 RTP/AVP 0 8 3 18 101

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:3 GSM/8000

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=silenceSupp:off - - - -

a=ptime:20

a=sendrecv

*Oct 11 15:37:47.196: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container

*Oct 11 15:37:47.196: //905/80BB30990800/SIP/Info/sipSPIhandle200OKInvite: Transaction active. Facilities will be queued.

*Oct 11 15:37:47.196: //905/80BB30990800/SIP/Info/sipSPIhandle200OKInvite: *** This ccb is the parent

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Error/sipSPIProcessNotifyCallInfoHeader: Call-Info header with for Unsolicited Notify Absent,Disabling Unsolicited Notifies

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1

SIP: Attribute mid, level 1 instance 1 not found.

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.0.101.9

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711ulaw) Negotiation Successful on Static Payload for m-line 1

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20

*Oct 11 15:37:47.200: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711ulaw ptime :20, codecbytes: 160

*Oct 11 15:37:47.200: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711ulaw

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of full named event(NE) match in fmtp list of events.

*Oct 11 15:37:47.200: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Info/sip_do_nse_negotiation: Remote NSE payload = local one = 0, Use it

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay

*Oct 11 15:37:47.200: //905/80BB30990800/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 11 15:37:47.200: //905/80BB30990800/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1

payload_type=0, codec_bytes=160, codec=g711ulaw, dtmf_relay=rtp-nte

stream_type=voice+dtmf (1), dest_ip_address=69.121.96.12, dest_port=14774

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING)

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Media/sipSPICompareStreams: stream 1 dest_port: old=14774 new=14774

*Oct 11 15:37:47.200: //905/80BB30990800/SIP/Media/sipSPIGetNewLocalMediaDirection:

New Remote Media Direction = SENDRECV

Present Local Media Direction = SENDRECV

New Local Media Direction = SENDRECV

retVal = 0

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Media/sipSPICompareStreams: Flags set for stream 1: RTP_CHANGE=Yes CAPS_CHANGE=Yes RSVP_ADDR_CHANGE=No RSVP_MEDIA_CHANGE=No

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Media/sipSPICompareSDP: Flags set for call: NEW_MEDIA=Yes DSPDNLD_REQD=Yes IPIP_MEDIA=Yes

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Media/sipSPIUpdCallWithSdpInfo:

Preferred Codec : g711ulaw, bytes :160

Preferred DTMF relay : rtp-nte

Preferred NTE payload : 101

Early Media : No

Delayed Media : Yes

Bridge Done : Yes

New Media : Yes

DSP DNLD Reqd : Yes

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.0.101.9

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_report_media_to_peer:

callId 905 peer 904 flags 0x207405 state STATE_RECD_PROCEEDING

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

CallID 905, sdp 0x48802F54 channels 0x492CF7A4

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/copy_channels:

callId 905 size 240 ptr 0x487310B4)

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Hndl ptype 0 mline 1

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711ulaw

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 5

*Oct 11 15:37:47.204: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=20,stream->negotiated_codec_bytes=160, coverted ptime=20 stream->mline_index=1, media_ndx=1

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Adding codec 5 ptype 0 time 20, bytes 160 as channel 0 mline 1 ss 0 69.121.96.12:14774

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Hndl ptype 8 mline 1

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711alaw

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Hndl ptype 3 mline 1

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec gsmfr

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Hndl ptype 18 mline 1

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Media/sipSPISelectCodecVersion: Codec (g729r8) is not in preferred list

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: An exact codec match not configured, using interoperable codec g729r8 pre-ietf

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g729r8 pre-ietf

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Hndl ptype 101 mline 1

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Call 905 dtmf ptype 101 nte/oob enabled

*Oct 11 15:37:47.204: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: setting ipip_caps DTMF to RFC2833: callid = 905, dtmf = 6

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 5

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Info/sipSPI_ipip_report_media_to_peer:

callId 905 flags 0x100 state STATE_RECD_PROCEEDING

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Info/sipSPI_ipip_report_media_to_peer:

Report change in call setup media

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Info/ccsip_update_srtp_caps: 4754: Posting Remote SRTP caps to other callleg.

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Media/sipSPIUpdCallWithSdpInfo:

Stream type : voice+dtmf

Media line : 1

State : STREAM_CHANGING (4)

Stream address type : 1

Callid : -1

Negotiated Codec : g711ulaw, bytes :160

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

Negotiated DTMF relay : rtp-nte

Negotiated NTE payload : 101 (tx), 101 (rx)

Negotiated CN payload : 0

Media Srce Addr/Port : [10.0.101.9]:16798

Media Dest Addr/Port : [69.121.96.12]:14774

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Media/sipSPIProcessRtpSessions: sipSPIProcessRtpSessions

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Media/sipSPIDeleteStream: Deleting stream 1 from the VOIP RTP library

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 905) to the VOIP RTP library

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.0.101.9

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info

laddr = 10.0.101.9, lport = 16798, raddr = 69.121.96.12, rport=14774, do_rtcp=TRUE

src_callid = 905, dest_callid = 904, stream type = voice+dtmf, stream direction = SENDRECV

media_ip_addr = 69.121.96.12, vrf tableid = 0 media_addr_type = 1

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Info/sipSPICreateRtpSession: sess: 48802D08 do_rtcp:1

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Media/sipSPICreateRtpSession: stun is disabled

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Info/sipSPIUpdateRtcpSession:

DTMF inb/oob iwf enabled 101

*Oct 11 15:37:47.208: //905/80BB30990800/SIP/Media/sipSPIGetNewLocalMediaDirection:

New Remote Media Direction = SENDRECV

Present Local Media Direction = SENDRECV

New Local Media Direction = SENDRECV

retVal = 0

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/State/sipSPIChangeStreamState: Stream (callid = 905) State changed from (STREAM_CHANGING) to (STREAM_ACTIVE)

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info

laddr = 10.0.101.9, lport = 16798, raddr = 69.121.96.12, rport=14774, do_rtcp=TRUE

src_callid = 905, dest_callid = 904, stream type = voice+dtmf, stream direction = SENDRECV

media_ip_addr = 69.121.96.12, vrf tableid = 0 media_addr_type = 1

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/Media/sipSPIUpdateRtcpSession: RTP session already created - update

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:4825A31C

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/Info/sipSPIUpdateRtcpSession:

DTMF inb/oob iwf enabled 101

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/Media/sipSPIGetNewLocalMediaDirection:

New Remote Media Direction = SENDRECV

Present Local Media Direction = SENDRECV

New Local Media Direction = SENDRECV

retVal = 0

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/Info/sipSPIProcessMediaChanges: DSPDNLD Reqd is true. Call DoCapsInd

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/Info/sipSPIhandle200OKInvite: ccsip_api_call_connect_media returned: SIP_SUCCESS

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/State/sipSPIChangeState: 0x492CE530 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_NONE) to (STATE_RECD_PROCEEDING, SUBSTATE_NONE)

*Oct 11 15:37:47.212: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container

*Oct 11 15:37:47.212: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container

*Oct 11 15:37:47.212: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/Info/sipSPIShrlCall: Check peer: 1 for Shared-Line call, callid: 905

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/Info/sipSPICreateAndStartRtpTimer:

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled.

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/Info/ccsip_api_call_connected: SDP_INFO PTR 0x4975EF00

*Oct 11 15:37:47.212: //905/80BB30990800/SIP/Info/ccsip_api_call_connected: CCSIP: outgoing send ACK with SDP

*Oct 11 15:37:47.212: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_MEDIA_EVENT

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/Info/sipSPIhandle200OKInvite: ccsip_api_call_connected returned: SIP_SUCCESS

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/State/sipSPIChangeState: 0x492CE530 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_NONE) to (SIP_STATE_RECD_SUCCESS, SUBSTATE_NONE)

*Oct 11 15:37:47.216: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 29

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/Info/act_handle_app_media_event: method = 107 state = 24

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/Info/act_handle_app_media_event: Received media sip event SIP_REQUEST_ANSWER

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/Info/sipSPISendAck: Associated container=0x4964CC08 to Ack

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/Transport/sipSPISendAck: Sending ACK to the transport layer

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/Transport/sipSPITransportSendMessage: msg=0x4961E574, addr=69.121.96.12, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x416E3694

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x4961E574

*Oct 11 15:37:47.216: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x4961E574, addr=69.121.96.12, port=5060, connId=2 for UDP

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/State/sipSPIChangeState: 0x492CE530 : State change from (SIP_STATE_RECD_SUCCESS, SUBSTATE_NONE) to (STATE_ACTIVE, SUBSTATE_NONE)

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/Call/sipSPICallInfo:

The Call Setup Information is:

Call Control Block (CCB) : 0x492CE530

State of The Call : STATE_ACTIVE

TCP Sockets Used : NO

Calling Number : 8586181234

Called Number : 8586182100

Source IP Address (Sig ): 10.0.101.9

Destn SIP Req Addr:Port : 69.121.96.12:5060

Destn SIP Resp Addr:Port : 69.121.96.12:5060

Destination Name : sip24.sip-me.net

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/Call/sipSPIMediaCallInfo:

Number of Media Streams: 1

Media Stream : 1

Negotiated Codec : g711ulaw

Negotiated Codec Bytes : 160

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

Negotiated Dtmf-relay : 6

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

Source IP Address (Media): 10.0.101.9

Source IP Port (Media): 16798

Destn IP Address (Media): 69.121.96.12

Destn IP Port (Media): 14774

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

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/Info/sipSPICallActive: Transaction Complete. Lock on Facilities released.

*Oct 11 15:37:47.216: //905/80BB30990800/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd

*Oct 11 15:37:47.232: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Sent:

ACK sip:8586182100@69.121.96.12:5060 SIP/2.0

Date: Thu, 11 Oct 2012 15:37:42 GMT

From: <>8586181234@sip24.sip-me.net>;tag=3312828-C6

Allow-Events: telephone-event

Content-Length: 241

Proxy-Authorization: Digest username="user_name",realm="asterisk",uri="sip:8586182100@sip24.sip-me.net:5060",response="cafa42a4d6152996172a85329c2e36c1",nonce="59e96ccd",algorithm=MD5

To: <>8586182100@sip24.sip-me.net>;tag=as104fbfbe

Content-Disposition: session;handling=required

Content-Type: application/sdp

Call-ID: 6E51CFEA-12F011E2-8017B7AB-F260055A@10.0.101.9

Via: SIP/2.0/UDP 10.0.101.9:5060;branch=z9hG4bK70D6C1

CSeq: 102 ACK

Max-Forwards: 70

v=0

o=CiscoSystemsSIP-GW-UserAgent 5646 1618 IN IP4 10.0.101.9

s=SIP Call

c=IN IP4 10.0.101.9

t=0 0

m=audio 16798 RTP/AVP 0 101

c=IN IP4 10.0.101.9

a=rtpmap:0 PCMU/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

*Oct 11 15:37:49.996: //905/80BB30990800/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:4825A31C

*Oct 11 15:37:50.000: //905/80BB30990800/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call.

*Oct 11 15:37:50.000: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT

*Oct 11 15:37:50.004: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 7

*Oct 11 15:37:50.004: //905/80BB30990800/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer

*Oct 11 15:37:50.004: //905/80BB30990800/SIP/Info/sipSPIGenerateAuthorizationResponse: HA1 is: 8d3e23df7b2e2b39752fe99a2e41073b

*Oct 11 15:37:50.004: //905/80BB30990800/SIP/Info/sipSPISendBye: Associated container=0x4964C9A0 to Bye

*Oct 11 15:37:50.008: //905/80BB30990800/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer

*Oct 11 15:37:50.008: //905/80BB30990800/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE

*Oct 11 15:37:50.008: //905/80BB30990800/SIP/Transport/sipSPITransportSendMessage: msg=0x4961E574, addr=69.121.96.12, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x416E30A0

*Oct 11 15:37:50.008: //905/80BB30990800/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

*Oct 11 15:37:50.008: //905/80BB30990800/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0

*Oct 11 15:37:50.008: //905/80BB30990800/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x4961E574

*Oct 11 15:37:50.008: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x4961E574, addr=69.121.96.12, port=5060, connId=2 for UDP

*Oct 11 15:37:50.008: //905/80BB30990800/SIP/Info/sentByeDisconnecting: Sent Bye Request, starting DisconnectTimer

*Oct 11 15:37:50.008: //905/80BB30990800/SIP/State/sipSPIChangeState: 0x492CE530 : State change from (STATE_ACTIVE, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)

*Oct 11 15:37:50.012: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Sent:

BYE sip:8586182100@69.121.96.12:5060 SIP/2.0

Reason: Q.850;cause=16

Date: Thu, 11 Oct 2012 15:37:42 GMT

From: <>8586181234@sip24.sip-me.net>;tag=3312828-C6

Timestamp: 1349969870

Content-Length: 0

User-Agent: Cisco-SIPGateway/IOS-12.x

Proxy-Authorization: Digest username="user_name",realm="asterisk",uri="sip:8586182100@69.121.96.12:5060",response="a4b3c1250bc501bfb8423a865ae645c5",nonce="59e96ccd",algorithm=MD5

To: <>8586182100@sip24.sip-me.net>;tag=as104fbfbe

Call-ID: 6E51CFEA-12F011E2-8017B7AB-F260055A@10.0.101.9

Via: SIP/2.0/UDP 10.0.101.9:5060;branch=z9hG4bK70E8C2

CSeq: 103 BYE

Max-Forwards: 70

*Oct 11 15:37:50.280: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [69.121.96.12]:5060

*Oct 11 15:37:50.280: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1

*Oct 11 15:37:50.280: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x4875B174

*Oct 11 15:37:50.280: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x4875B174, addr=69.121.96.12, port=5060, connid=2, transport=UDP

*Oct 11 15:37:50.280: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog

*Oct 11 15:37:50.280: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 200 OK

Via: SIP/2.0/UDP 10.0.101.9:5060;branch=z9hG4bK70E8C2;received=121.1.2.9

From: <>8586181234@sip24.sip-me.net>;tag=3312828-C6

To: <>8586182100@sip24.sip-me.net>;tag=as104fbfbe

Call-ID: 6E51CFEA-12F011E2-8017B7AB-F260055A@10.0.101.9

CSeq: 103 BYE

User-Agent: packetrino

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO

Supported: replaces

Content-Length: 0

*Oct 11 15:37:50.280: //905/80BB30990800/SIP/Info/sipSPIIcpifUpdate: CallState: 4 Playout: 0 DiscTime:5356078 ConnTime 5355771

*Oct 11 15:37:50.284: //905/80BB30990800/SIP/State/sipSPIChangeState: 0x492CE530 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE)

*Oct 11 15:37:50.284: //905/80BB30990800/SIP/Call/sipSPICallInfo:

The Call Setup Information is:

Call Control Block (CCB) : 0x492CE530

State of The Call : STATE_DEAD

TCP Sockets Used : NO

Calling Number : 8586181234

Called Number : 8586182100

Source IP Address (Sig ): 10.0.101.9

Destn SIP Req Addr:Port : 69.121.96.12:5060

Destn SIP Resp Addr:Port : 69.121.96.12:5060

Destination Name : sip24.sip-me.net

*Oct 11 15:37:50.284: //905/80BB30990800/SIP/Call/sipSPIMediaCallInfo:

Number of Media Streams: 1

Media Stream : 1

Negotiated Codec : g711ulaw

Negotiated Codec Bytes : 160

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

Negotiated Dtmf-relay : 6

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

Source IP Address (Media): 10.0.101.9

Source IP Port (Media): 16798

Destn IP Address (Media): 69.121.96.12

Destn IP Port (Media): 14774

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

*Oct 11 15:37:50.284: //905/80BB30990800/SIP/Call/sipSPICallInfo:

Disconnect Cause (CC) : 16

Disconnect Cause (SIP) : 200

*Oct 11 15:37:50.284: //905/80BB30990800/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 389

*Oct 11 15:37:50.284: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[898] removed.

*Oct 11 15:37:50.284: //905/80BB30990800/SIP/Info/sipSPIUdeleteCcbFromUACTable: ****Deleting from UAC table.

*Oct 11 15:37:50.284: //905/80BB30990800/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x492CE530 key=6E51CFEA-12F011E2-8017B7AB-F260055A@10.0.101.9

*Oct 11 15:37:50.284: //905/80BB30990800/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd

*Oct 11 15:37:50.284: //905/80BB30990800/SIP/Info/ccsip_qos_cleanup: Entry

*Oct 11 15:37:50.288: //905/80BB30990800/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed

*Oct 11 15:37:50.288: //905/80BB30990800/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 492CE530

*Oct 11 15:37:50.288: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[898]

Suresh Subramanian · ‎10-11-2012

Hi,

we could see that the provider sends the 183 session progress with SDP contents as below.

*Oct 11 15:37:45.068: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 183 Session Progress

.Via: SIP/2.0/UDP 10.0.101.9:5060;branch=z9hG4bK70CF22;received=121.1.2.9

.From: <>8586181234@sip24.sip-me.net>;tag=3312828-C6

.To: <>8586182100@sip24.sip-me.net>;tag=as104fbfbe

.Call-ID: 6E51CFEA-12F011E2-8017B7AB-F260055A@10.0.101.9

.CSeq: 102 INVITE

.User-Agent: packetrino

.Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO

.Supported: replaces

.Contact: <8586182100>

.Content-Type: application/sdp

.Content-Length: 334

.

v=0

.o=root 1763 1763 IN IP4 69.121.96.12

.s=session

.c=IN IP4 69.121.96.12

.t=0 0

.m=audio 14774 RTP/AVP 0 8 3 18 101

.a=rtpmap:0 PCMU/8000

.a=rtpmap:8 PCMA/8000

.a=rtpmap:3 GSM/8000

.a=rtpmap:18 G729/8000

.a=fmtp:18 annexb=no

.a=rtpmap:101 telephone-event/8000

.a=fmtp:101 0-16

.a=silenceSupp:off - - - -

.a=ptime:20

.a=sendrecv

>> It indicates that the service provider is generating the ringback tone.however to confirm the same, we would need to capture the "debug voip ccapi inout" along with "debug ccsip all" for a test call.

>> to capture multiple debugs: https://supportforums.cisco.com/docs/DOC-16310

>> Also, could you please post the running config of the sip gateway?

>> is this gateway connected to CUCM as H.323 GW?

Thanks

//Suresh Please rate all the useful posts.

gcrawford2005 · ‎10-11-2012

Below is the output of the debug voip ccapi inout

===================================

*Oct 11 23:40:34.418: //-1/00B0710E1900/CCAPI/cc_api_display_ie_subfields:

cc_api_call_setup_ind_common:

cisco-username=FirstName LastName

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

cisco-ani=858-295-8888

cisco-anitype=0

cisco-aniplan=0

cisco-anipi=0

cisco-anisi=1

dest=8009993355

cisco-desttype=0

cisco-destplan=0

cisco-rdie=FFFFFFFF

cisco-rdn=

cisco-rdntype=-1

cisco-rdnplan=-1

cisco-rdnpi=-1

cisco-rdnsi=-1

cisco-redirectreason=-1 fwd_final_type =0

final_redirectNumber =

hunt_group_timeout =0

*Oct 11 23:40:34.418: //-1/00B0710E1900/CCAPI/cc_api_call_setup_ind_common:

Interface=0x48336EE0, Call Info(

Calling Number=858-295-8888,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),

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

Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,

Incoming Dial-peer=1, Progress Indication=NULL(0), Calling IE Present=TRUE,

Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=1420

*Oct 11 23:40:34.418: //-1/00B0710E1900/CCAPI/ccCheckClipClir:

In: Calling Number=858-295-8888(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)

*Oct 11 23:40:34.422: //-1/00B0710E1900/CCAPI/ccCheckClipClir:

Out: Calling Number=858-295-8888(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)

*Oct 11 23:40:34.422: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Oct 11 23:40:34.422: :cc_get_feature_vsa malloc success

*Oct 11 23:40:34.422: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Oct 11 23:40:34.422: cc_get_feature_vsa count is 1

*Oct 11 23:40:34.422: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Oct 11 23:40:34.422: :FEATURE_VSA attributes are: feature_name:0,feature_time:1197531656,feature_id:47

*Oct 11 23:40:34.422: //1420/00B0710E1900/CCAPI/cc_api_call_setup_ind_common:

Set Up Event Sent;

Call Info(Calling Number=858-295-8888(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),

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

*Oct 11 23:40:34.422: //1420/00B0710E1900/CCAPI/cc_process_call_setup_ind:

Event=0x490C14D0

*Oct 11 23:40:34.422: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:

Try with the demoted called number 8009993355

*Oct 11 23:40:34.426: //1420/00B0710E1900/CCAPI/ccCallSetContext:

Context=0x475E4904

*Oct 11 23:40:34.426: //1420/00B0710E1900/CCAPI/cc_process_call_setup_ind:

>>>>CCAPI handed cid 1420 with tag 1 to app "_ManagedAppProcess_Default"

*Oct 11 23:40:34.426: //1420/00B0710E1900/CCAPI/ccCallProceeding:

Progress Indication=NULL(0)

*Oct 11 23:40:34.426: //1420/00B0710E1900/CCAPI/ccCallSetupRequest:

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

Outgoing Dial-peer=1, Params=0x475E5844, Progress Indication=NULL(0)

*Oct 11 23:40:34.430: //1420/00B0710E1900/CCAPI/ccCheckClipClir:

In: Calling Number=858-295-8888(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)

*Oct 11 23:40:34.430: //1420/00B0710E1900/CCAPI/ccCheckClipClir:

Out: Calling Number=858-295-8888(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)

*Oct 11 23:40:34.430: //1420/00B0710E1900/CCAPI/ccCallSetupRequest:

Destination Pattern=.T, Called Number=8009993355, Digit Strip=FALSE

*Oct 11 23:40:34.430: //1420/00B0710E1900/CCAPI/ccCallSetupRequest:

Calling Number=858-295-8888(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),

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

Redirect Number=, Display Info=

Account Number=FirstName LastName, Final Destination Flag=TRUE,

Guid=00B0710E-4957-7107-1900-2F020A0165C9, Outgoing Dial-peer=1

*Oct 11 23:40:34.430: //1420/00B0710E1900/CCAPI/cc_api_display_ie_subfields:

ccCallSetupRequest:

cisco-username=FirstName LastName

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

cisco-ani=858-295-8888

cisco-anitype=0

cisco-aniplan=0

cisco-anipi=0

cisco-anisi=1

dest=8009993355

cisco-desttype=0

cisco-destplan=0

cisco-rdie=FFFFFFFF

cisco-rdn=

cisco-rdntype=-1

cisco-rdnplan=-1

cisco-rdnpi=-1

cisco-rdnsi=-1

cisco-redirectreason=-1 fwd_final_type =0

final_redirectNumber =

hunt_group_timeout =0

*Oct 11 23:40:34.430: //1420/00B0710E1900/CCAPI/ccIFCallSetupRequestPrivate:

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

Call Params(Calling Number=858-295-8888,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),

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

Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=1, Call Count On=FALSE,

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

*Oct 11 23:40:34.430: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Oct 11 23:40:34.430: :cc_get_feature_vsa malloc success

*Oct 11 23:40:34.430: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Oct 11 23:40:34.430: cc_get_feature_vsa count is 2

*Oct 11 23:40:34.430: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Oct 11 23:40:34.430: :FEATURE_VSA attributes are: feature_name:0,feature_time:1197531432,feature_id:48

*Oct 11 23:40:34.430: //1421/00B0710E1900/CCAPI/ccIFCallSetupRequestPrivate:

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

*Oct 11 23:40:34.434: //1421/00B0710E1900/CCAPI/ccCallSetContext:

Context=0x475E57F4

*Oct 11 23:40:34.434: //1420/00B0710E1900/CCAPI/ccSaveDialpeerTag:

Outgoing Dial-peer=1

*Oct 11 23:40:34.434: //1421/00B0710E1900/CCAPI/cc_api_call_proceeding:

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

*Oct 11 23:40:36.430: //1421/00B0710E1900/CCAPI/cc_api_caps_ind:

Destination Interface=0x0, Destination Call Id=-1, Source Call Id=1421,

Caps(Codec=0x1, Fax Rate=0x2, Vad=0x2,

Modem=0x0, Codec Bytes=160, Signal Type=2)

*Oct 11 23:40:36.430: //1421/00B0710E1900/CCAPI/cc_api_caps_ind:

Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),

Playout Max=1000(ms), Fax Nom=300(ms))

*Oct 11 23:40:36.430: //1421/00B0710E1900/CCAPI/cc_api_event_indication:

Event=90, Call Id=1421

*Oct 11 23:40:36.430: //1421/00B0710E1900/CCAPI/cc_api_event_indication:

Event Is Sent To Conferenced SPI(s) Directly

*Oct 11 23:40:36.430: //1421/00B0710E1900/CCAPI/cc_api_call_cut_progress:

Interface=0x489F756C, Progress Indication=INBAND(8), Signal Indication=SIGNAL RINGBACK(1),

Cause Value=0

*Oct 11 23:40:36.430: //1421/00B0710E1900/CCAPI/cc_api_call_cut_progress:

Call Entry(Responsed=TRUE)

*Oct 11 23:40:36.434: //1420/00B0710E1900/CCAPI/ccCallCutProgress:

Progress Indication=INBAND(8), Signal Indication=SIGNAL RINGBACK(1), Cause Value=0

Voice Call Send Alert=FALSE, Call Entry(Alert Sent=FALSE)

*Oct 11 23:40:36.434: //1420/00B0710E1900/CCAPI/ccCallCutProgress:

Call Entry(Responsed=TRUE)

*Oct 11 23:40:36.434: //1421/00B0710E1900/CCAPI/cc_api_get_called_ccm_detected:

CallInfo(ccm detected=0)

*Oct 11 23:40:36.434: //1420/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:

(confID=0x48801C44, callID1=0x58C, callID2=0x58D, tag=0x0)

*Oct 11 23:40:36.434: //1420/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:

(confID=0x48801C44, callID1=0x58C, gcid=0-0-0-0, tag=0x0)

*Oct 11 23:40:36.434: //1421/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:

(confID=0x48801C44, callID2=0x58D, gcid=0-0-0-0, tag=0x0)

*Oct 11 23:40:36.434: //1420/00B0710E1900/CCAPI/ccConferenceCreate:

Conference Id=0x48801C44, Call Id1=1420, Call Id2=1421, Tag=0x0

*Oct 11 23:40:36.438: //1420/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Oct 11 23:40:36.438: cc_api_get_xcode_stream : 4510

*Oct 11 23:40:36.438: //1420/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:

Conference Id=0x18, Source Interface=0x48336EE0, Source Call Id=1420,

Destination Call Id=1421, Disposition=0x0, Tag=0x0

*Oct 11 23:40:36.438: //1421/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:

*Oct 11 23:40:36.438: cc_api_get_xcode_stream : 4510

*Oct 11 23:40:36.438: //1421/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:

Conference Id=0x18, Source Interface=0x489F756C, Source Call Id=1421,

Destination Call Id=1420, Disposition=0x0, Tag=0x0

*Oct 11 23:40:36.438: //1420/00B0710E1900/CCAPI/cc_generic_bridge_done:

Conference Id=0x18, Source Interface=0x489F756C, Source Call Id=1421,

Destination Call Id=1420, Disposition=0x0, Tag=0x0

*Oct 11 23:40:36.438: //1420/00B0710E1900/CCAPI/ccConferenceCreate:

Call Entry(Conference Id=0x18, Destination Call Id=1421)

*Oct 11 23:40:36.438: //1421/00B0710E1900/CCAPI/ccConferenceCreate:

Call Entry(Conference Id=0x18, Destination Call Id=1420)

*Oct 11 23:40:36.442: //1420/00B0710E1900/CCAPI/cc_process_notify_bridge_done:

Conference Id=0x18, Call Id1=1420, Call Id2=1421

*Oct 11 23:40:36.442: //1420/00B0710E1900/CCAPI/ccCallNotify:

Data Bitmask=0x7, Call Id=1420

*Oct 11 23:40:36.442: //1421/00B0710E1900/CCAPI/cc_api_get_called_ccm_detected:

CallInfo(ccm detected=0)

*Oct 11 23:40:36.466: //1420/00B0710E1900/CCAPI/cc_api_caps_ind:

Destination Interface=0x489F756C, Destination Call Id=1421, Source Call Id=1420,

Caps(Codec=0x3, Fax Rate=0x2, Vad=0x2,

Modem=0x0, Codec Bytes=20, Signal Type=2)

*Oct 11 23:40:36.466: //1420/00B0710E1900/CCAPI/cc_api_caps_ind:

Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),

Playout Max=1000(ms), Fax Nom=300(ms))

*Oct 11 23:40:36.466: //1421/00B0710E1900/CCAPI/cc_api_caps_ack:

Destination Interface=0x48336EE0, Destination Call Id=1420, Source Call Id=1421,

Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=ON(0x2),

Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=1)

*Oct 11 23:40:36.466: //1420/00B0710E1900/CCAPI/cc_api_caps_ack:

Destination Interface=0x489F756C, Destination Call Id=1421, Source Call Id=1420,

Caps(Codec=gsmefr(0x0), Fax Rate=Invalid(0x0), Vad=Invalid(0x0),

Modem=OFF(0x0), Codec Bytes=0, Signal Type=0, Seq Num Start=0)

*Oct 11 23:40:36.470: //1420/00B0710E1900/CCAPI/cc_api_event_indication:

Event=153, Call Id=1420

*Oct 11 23:40:36.470: //1420/00B0710E1900/CCAPI/cc_api_event_indication:

Event Is Sent To Conferenced SPI(s) Directly

*Oct 11 23:40:36.474: //1421/00B0710E1900/CCAPI/cc_api_event_indication:

Event=154, Call Id=1421

*Oct 11 23:40:36.474: //1421/00B0710E1900/CCAPI/cc_api_event_indication:

Event Is Sent To Conferenced SPI(s) Directly

*Oct 11 23:40:36.522: //1420/00B0710E1900/CCAPI/cc_api_event_indication:

Event=154, Call Id=1420

*Oct 11 23:40:36.522: //1420/00B0710E1900/CCAPI/cc_api_event_indication:

Event Is Sent To Conferenced SPI(s) Directly

*Oct 11 23:40:37.270: //1421/00B0710E1900/CCAPI/cc_api_event_indication:

Event=90, Call Id=1421

*Oct 11 23:40:37.270: //1421/00B0710E1900/CCAPI/cc_api_event_indication:

Event Is Sent To Conferenced SPI(s) Directly

*Oct 11 23:40:37.270: //1421/00B0710E1900/CCAPI/cc_api_call_connected:

Interface=0x489F756C, Data Bitmask=0x1, Progress Indication=NULL(0),

Connection Handle=0

*Oct 11 23:40:37.274: //1421/00B0710E1900/CCAPI/cc_api_call_connected:

Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)

*Oct 11 23:40:37.278: //1420/00B0710E1900/CCAPI/ccCallConnect:

Progress Indication=NULL(0), Data Bitmask=0x1

*Oct 11 23:40:37.278: //1421/00B0710E1900/CCAPI/cc_api_get_called_ccm_detected:

CallInfo(ccm detected=0)

*Oct 11 23:40:37.278: //1420/00B0710E1900/CCAPI/ccCallConnect:

Call Entry(Connected=TRUE, Responsed=TRUE)

*Oct 11 23:40:37.278: //1420/00B0710E1900/CCAPI/ccCallNotify:

Data Bitmask=0x7, Call Id=1420

*Oct 11 23:40:37.278: //1421/00B0710E1900/CCAPI/cc_api_get_called_ccm_detected:

CallInfo(ccm detected=0)

===================

Below is the running config

===================

Current configuration : 2756 bytes

!

version 12.4

service timestamps debug datetime msec

service timestamps log datetime msec

service password-encryption

!

hostname ***********

!

boot-start-marker

boot-end-marker

!

logging message-counter syslog

!

no aaa new-model

!

dot11 syslog

ip source-route

!

ip cef

!

ip domain name *****.local

ip name-server 100.0.100.100

ip name-server 100.1.100.100

no ipv6 cef

!

multilink bundle-name authenticated

!

voice service voip

allow-connections h323 to sip

allow-connections sip to h323

allow-connections sip to sip

no supplementary-service sip moved-temporarily

no supplementary-service sip refer

h323

sip

!

voice class codec 1

codec preference 1 g711ulaw

codec preference 2 g711alaw

!

voice class h323 1

h225 timeout tcp establish 2

h225 timeout call-proceeding 1

h225 timeout setup 3

call start fast

telephony-service ccm-compatible

ccm-compatible

!

voice-card 0

dsp services dspfarm

!

username **** privilege 15 secret 5 ****

Ringback over SIP lines (CUCMv7.1.5 --> 2811 --> SIP Provider)