cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
8304
Views
5
Helpful
12
Replies

DTMF in SIP Trunk with G729 issue

robert.bernal
Level 1
Level 1

Hello  all,

Im setting up a Sip Trunk with Telefonica Movistar,  The scenario is  CCM6  ==>>   GW3845  ==>>  SIP Provider.

I can make calls without  issue, but the  DTMF its not working, and the Service provider says that he didn´t see nothing.

Im  using G729 with RFC2833 and RTP-NTE.

I´ll appreciate all your  help. to resolve this issue

Dial peers:

In:

dial-peer voice 6100 voip
translation-profile incoming XLATECUCM
destination-pattern [1-9]...$
voice-class sip g729 annexb-all
voice-class sip early-offer forced
session protocol sipv2
session target ipv4:10.0.70.254
incoming called-number 91..
dtmf-relay rtp-nte
codec g729br8
fax-relay sg3-to-g3
fax rate 14400
fax protocol t38 ls-redundancy 0 hs-redundancy 0 fallback pass-through g711ulaw

Out:

dial-peer voice 7000 voip
destination-pattern 40504T
voice-class sip dtmf-relay force rtp-nte
voice-class sip g729 annexb-all
voice-class sip early-offer forced
session protocol sipv2
session target ipv4:200.39.13.4
dtmf-relay rtp-nte

codec g729br8
fax-relay sg3-to-g3
fax rate 14400
no vad

DEBUG:

SIP Call info tracing is enabled
GW-01#
*Nov 25 22:24:59.241: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.0.70.254]:5060
*Nov 25 22:24:59.241: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Nov 25 22:24:59.241: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Nov 25 22:24:59.241: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x6972B3B4) with key=[2406] to table
*Nov 25 22:24:59.241: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
*Nov 25 22:24:59.245: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckIpip: VOIP dialpeer (peer=0x67750C44) found for sip_user: 405048181569600
*Nov 25 22:24:59.245: //-1/337D3B869EA7/SIP/Info/ccsip_set_cc_cause_for_spi_err: Categorized cause:100, category:100
*Nov 25 22:24:59.245: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_set_release_source_for_peer: ownCallId[-1], src[6]
*Nov 25 22:24:59.245: //-1/337D3B869EA7/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
*Nov 25 22:24:59.245: //-1/337D3B869EA7/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x6972B3B4 key=71bb8f80-b0d1cb64-3f6-fe46000a@10.0.70.254405048181569600
*Nov 25 22:24:59.245: //-1/337D3B869EA7/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table.
*Nov 25 22:24:59.245: //-1/337D3B869EA7/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x6972B3B4 key=71bb8f80-b0d1cb64-3f6-fe46000a@10.0.70.25495CABBC-8B6
*Nov 25 22:24:59.245: //-1/337D3B869EA7/SIP/Info/sentErrResDisconnecting: Sent an 3456XX Error Response
*Nov 25 22:24:59.245: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.0.70.254]:5060
*Nov 25 22:24:59.245: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Nov 25 22:24:59.245: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Nov 25 22:24:59.245: //-1/337D3B869EA7/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x6972B3B4
*Nov 25 22:24:59.245: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
*Nov 25 22:24:59.245: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[2406] removed.
*Nov 25 22:24:59.245: //-1/337D3B869EA7/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
*Nov 25 22:24:59.245: //-1/337D3B869EA7/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x6972B3B4 key=71bb8f80-b0d1cb64-3f6-fe46000a@10.0.70.254405048181569600
*Nov 25 22:24:59.245: //-1/337D3B869EA7/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
*Nov 25 22:24:59.245: //-1/337D3B869EA7/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x6972B3B4 key=71bb8f80-b0d1cb64-3f6-fe46000a@10.0.70.25495CABBC-8B6
*Nov 25 22:24:59.249: //-1/337D3B869EA7/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
*Nov 25 22:24:59.249: //-1/337D3B869EA7/SIP/Info/ccsip_qos_cleanup: Entry
*Nov 25 22:24:59.249: //-1/337D3B869EA7/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
*Nov 25 22:24:59.249: //-1/337D3B869EA7/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 6972B3B4
*Nov 25 22:24:59.249: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[2406]
*Nov 25 22:24:59.249: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.0.70.254]:5060
*Nov 25 22:24:59.249: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Nov 25 22:24:59.249: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Nov 25 22:24:59.249: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x70F17964) with key=[2407] to table
*Nov 25 22:24:59.249: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
*Nov 25 22:24:59.249: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckIpip: VOIP dialpeer (peer=0x67750C44) found for sip_user: 405048181569600
*Nov 25 22:24:59.249: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
*Nov 25 22:24:59.249: //-1/337E73D69EA8/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
*Nov 25 22:24:59.249: //-1/337E73D69EA8/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x70F17964 key=71bb8f80-b0d1cb64-3f7-fe46000a@10.0.70.254405048181569600
*Nov 25 22:24:59.249: //-1/337E73D69EA8/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id
*Nov 25 22:24:59.249: //-1/337E73D69EA8/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 405048181569600
*Nov 25 22:24:59.249: //-1/337E73D69EA8/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 4504
*Nov 25 22:24:59.249: //-1/337E73D69EA8/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name Administrador BD y Prog, number 4504, Calling oct3 0x00, oct_3a 0x80, Called number 405048181569600
*Nov 25 22:24:59.249: //-1/337E73D69EA8/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 4504
*Nov 25 22:24:59.253: //-1/337E73D69EA8/SIP/Info/sipSPIGetCallConfig: Peer tag 6100 matched for incoming call
*Nov 25 22:24:59.253: //-1/337E73D69EA8/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
*Nov 25 22:24:59.253: //-1/337E73D69EA8/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
*Nov 25 22:24:59.253: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetCallConfig: voice class SIP Profiles tag is set : 1
*Nov 25 22:24:59.253: //-1/337E73D69EA8/SIP/Info/sipSPIGetCallConfig: Not using Voice Class Codec
*Nov 25 22:24:59.253: //-1/337E73D69EA8/SIP/Info/sipSPIGetCallConfig: Checking Video Type Rate=-1 video_codec_allowed=1F
*Nov 25 22:24:59.253: //-1/337E73D69EA8/SIP/Info/sipSPIGetCallConfig: xcoder high-density disabled
*Nov 25 22:24:59.253: //-1/337E73D69EA8/SIP/Info/sipSPIGetCallConfig: Flow Mode set to FLOW_THROUGH
*Nov 25 22:24:59.253: //-1/337E73D69EA8/SIP/Info/sipSPIGetCallConfig: Media forking disabled
*Nov 25 22:24:59.253: //-1/337E73D69EA8/SIP/Info/sipSPIContinueNewMsgInvite: Calling name Administrador BD y Prog, number 4504, Calling oct3 0x00, oct_3a 0x80, ext_priv 0x00, Called number 405048181569600, oct3 0x00
*Nov 25 22:24:59.253: //-1/337E73D69EA8/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE
*Nov 25 22:24:59.253: //-1/337E73D69EA8/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPINegotiateSessionExpires: Min-SE Header: 2000
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPINegotiateSessionExpires:
Session-Expires value: 2000 refresher: 3
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_Add_SessionExpiresParamsToContainer: Session-refresh parameters added to container minse = 2000 session expire = 2000 refresher = 3
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found
*Nov 25 22:24:59.253: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentSDP: No SDP found in inbound container
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPIDoQoSNegotiationWithNoMediaLine: Entry
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPIDoQoSNegotiationWithNoMediaLine: Local Precondition: 1, Remote Precondition: 1
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 3472, sdp 0x680A0DC8 channels 0x70F18C04
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/copy_channels:
callId 3472 size 0 ptr 0x6CE38E94)
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Delayed media case...creating new stream
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=16538
*Nov 25 22:24:59.253: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729r8 codecbytes :20, ptime: 20
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = 71bb8f80-b0d1cb64-3f7-fe46000a@10.0.70.254
*Nov 25 22:24:59.253: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_store_channel_info: negotiated dtmf not available, using dialpeer config dtmf = 8
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPIShrlCall: Check peer: 6100 for Shared-Line call, callid: 3472
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/ccsip_set_bearer_capability:
   Bearer Capability: Speech (0x00)
*Nov 25 22:24:59.253: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
*Nov 25 22:24:59.253: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
*Nov 25 22:24:59.253: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message

*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS_DELAYED_MEDIA
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id D90 to table
*Nov 25 22:24:59.253: //3472/337E73D69EA8/SIP/Info/sipSPIProcessContactInfo: Previous Hop 10.0.70.254:5060
*Nov 25 22:24:59.257: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x70ED9894) with key=[2408] to table
*Nov 25 22:24:59.257: //3473/000000000000/SIP/Info/ccsip_call_setup_request: Before processing SETUP REQccb->pld.flags_ipip = 200
*Nov 25 22:24:59.257: //3473/000000000000/SIP/Info/ccsip_call_setup_request: midcall-signaling passthru enabled
*Nov 25 22:24:59.257: //3473/000000000000/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP
*Nov 25 22:24:59.257: //3473/000000000000/SIP/Info/ccsip_call_setup_request: This is IPIP Delayed Offer to Early Offer Call.peer_channels = 0x0, peer_param = 0x6CB6D2E4, callID= 3473, peer_callID = 3472
*Nov 25 22:24:59.257: //3473/000000000000/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP
*Nov 25 22:24:59.257: //3473/000000000000/SIP/Info/ccsip_call_setup_request: After processing SETUP REQccb->pld.flags_ipip = 400000
*Nov 25 22:24:59.257: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : 200.36.172.2 target_port : 5060

*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/ccsip_call_setup_request: Incrementing call counter in dial-peer [1000]
*Nov 25 22:24:59.257: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: 
*Nov 25 22:24:59.257: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 162)
*Nov 25 22:24:59.257: //3472/337E73D69EA8/SIP/Info/ccsip_event_handler:
ccsip_event_handler: peer ID 3473 chans 0x6D015970 event 162 flags 0x40201C 0x300 0x201 data 0x6D015970
*Nov 25 22:24:59.257: //3472/337E73D69EA8/SIP/Info/ccsip_event_handler:
ccsip_event_handler: CC_EV_H245_SET_MODE: peer ID 3473 chans 0x6D015970 event 162 flags 0x40201C 0x300 0x201 data 0x6D015970, type = 1
*Nov 25 22:24:59.257: //3472/337E73D69EA8/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP
*Nov 25 22:24:59.257: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED
*Nov 25 22:24:59.257: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 3
*Nov 25 22:24:59.257: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 2
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id D91 to table
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPIGetCallConfig: preferred_codec set[0] type :No Codec    bytes: 0
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPIGetCallConfig: Media forking disabled
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
*Nov 25 22:24:59.257: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetCallConfig: voice class SIP Profiles tag is set : 1
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 2
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPIGetCallConfig: xcoder high-density disabled
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPIGetCallConfig: Flow Mode set to FLOW_THROUGH
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPIGetCallConfig: Media forking disabled
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/preprocessSetup:
This is a not a SIGO Call -, could be DM call
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_call_setup: No video caps posted by peer
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_call_setup: We support only FLOW_THROUGH for DO - EO
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_call_setup: xcoder high-density disabled
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_call_setup: Flow Mode set to FLOW_THROUGH
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:
callid 3473, channels 0x0 caps 0x6CFA2F4C
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_setSessionExpiresParams:
Session refresh values minse = 2000 session expire = 2000 refresher = 3
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPIAddSDPPayloadAttributes:
max_event 15
*Nov 25 22:24:59.257: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPIOutgoingCallSDP: Creating recv-only stream for outbound call
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sip_gw_pre_setup_add_sdp_container: SDP container added
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPIAddMLPPServicesInfo: No MLP Info available on incoming leg
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPIShrlGetInstanceInfo: Obtained the call instance 0 for non-shared-line '40504.T' with callid: 3473
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPIAddCiscoGcid: Gcid value not set - not adding header.
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_set_history_info_header: No HI header recvd from container
*Nov 25 22:24:59.257: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_set_diversion_header: No diversion header recvd from container
*Nov 25 22:24:59.261: //3473/337E73D69EA8/SIP/Info/act_idle_continue_call_setup:
*Nov 25 22:24:59.261: //3473/337E73D69EA8/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
*Nov 25 22:24:59.261: //3473/337E73D69EA8/SIP/Info/sipSPIUaddCcbToUACTable: ****Adding to UAC table.
*Nov 25 22:24:59.261: //3473/337E73D69EA8/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x70ED9894 key=338048E7-D94811DE-9EAE8264-5EE14E53@200.39.18.246
*Nov 25 22:24:59.261: //3473/337E73D69EA8/SIP/Info/sipSPIUsetBillingProfile: sipCallId for billing records = 338048E7-D94811DE-9EAE8264-5EE14E53@200.39.18.246
*Nov 25 22:24:59.261: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
*Nov 25 22:24:59.261: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIgetRegistrarHost: registrar is not configured
*Nov 25 22:24:59.261: //3473/337E73D69EA8/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat
*Nov 25 22:24:59.261: //3473/337E73D69EA8/SIP/Info/sipSPIGenerateHI: GeneHI: <sip:405048181569600@200.36.172.2:5060>;index=1

*Nov 25 22:24:59.261: //3473/337E73D69EA8/SIP/Info/sipSPISendInvite: Associated container=0x6CB6F4CC to Invite
*Nov 25 22:24:59.261: //-1/xxxxxxxxxxxx/SIP/Info/sip_profiles_application_modify_remove_header: Supported is removed from the SIP message
*Nov 25 22:24:59.261: //-1/xxxxxxxxxxxx/SIP/Info/sip_profiles_application_modify_remove_header: Min-SE is removed from the SIP message
*Nov 25 22:24:59.261: //-1/xxxxxxxxxxxx/SIP/Info/sip_profiles_application_modify_remove_header: Session-Expires is removed from the SIP message
*Nov 25 22:24:59.261: //-1/xxxxxxxxxxxx/SIP/Info/httpish_msg_get_complete_header: No holder for this header
*Nov 25 22:24:59.261: //-1/xxxxxxxxxxxx/SIP/Info/sip_profiles_application_modify_remove_header: Unable to get header from stack
*Nov 25 22:24:59.261: //3473/337E73D69EA8/SIP/Info/sentInviteRequest: Sent Invite in state STATE_IDLE
*Nov 25 22:24:59.261: //-1/xxxxxxxxxxxx/SIP/Info/sentInviteRequest: Transaction active. Facilities will be queued.
*Nov 25 22:24:59.261: //3473/337E73D69EA8/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
*Nov 25 22:24:59.261: //3473/337E73D69EA8/SIP/Info/sipSPICreateRtpSession: sess: 69AC3E44 do_rtcp:0
*Nov 25 22:24:59.389: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [200.36.172.2]:5060
*Nov 25 22:24:59.389: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Nov 25 22:24:59.389: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Nov 25 22:24:59.393: //3473/337E73D69EA8/SIP/Info/sipSPICheckResponse: INVITE response with no RSEQ - disable IS_REL1XX
*Nov 25 22:24:59.861: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [200.36.172.2]:5060
*Nov 25 22:24:59.861: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Nov 25 22:24:59.861: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPICheckResponse: INVITE response with no RSEQ - disable IS_REL1XX
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/ccsip_api_update_allowed: UPDATE(1) allowed
*Nov 25 22:24:59.861: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPIProcessNotifyCallInfoHeader: Callinfo parsed - Destination url = <sip:200.36.172.2>, duration = 1000

*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPIDoAudioNegotiation: Codec (g729br8) Negotiation Successful on Static Payload for m-line 1
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20
*Nov 25 22:24:59.861: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g729br8 ptime :20, codecbytes: 20
*Nov 25 22:24:59.861: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729br8 codecbytes :20, ptime: 20
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved.
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of full named event(NE) match in fmtp list of events.
*Nov 25 22:24:59.861: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
*Nov 25 22:24:59.861: //3473/337E73D69EA8/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
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1
    payload_type=18, codec_bytes=20, codec=g729br8, dtmf_relay=rtp-nte
    stream_type=voice+dtmf (1), dest_ip_address=200.36.172.3, dest_port=26528
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 3473 peer 3472 flags 0x400001 state STATE_RECD_PROCEEDING
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 3473, sdp 0x727EC760 channels 0x70EDAB34
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/copy_channels:
callId 3473 size 0 ptr 0x6CE7C990)
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 18 mline 1
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g729br8
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/codec_found:
Codec to be matched: 12
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 12

*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: DO to EO case.If terminating side has sent more than one codec in the answer SDP, send only negotiated codec in ChannelInfo structure to peer leg.
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Report only negotiated codec (g729br8) to peer leg.
*Nov 25 22:24:59.861: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729br8 codecbytes :20, ptime: 20
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding negotiated codec 12 ptype 18 time 20,   bytes 20 as channel 0 mline 1 ss 1 200.36.172.3:26528
*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 12

*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1

*Nov 25 22:24:59.861: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 3473 flags 0x100 state STATE_RECD_PROCEEDING
*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer:
Report initial call media
*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0x400018, ccb->pld.flags_ipip 0x400001

*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer: Post CAPS to peer.

*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/ccsip_caps_ind: Entry
*Nov 25 22:24:59.865: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_caps_ind:
destCallID=3472, srcCallID=3473,
                         peer_ccb->call_info.currentLocalName=Administrador BD y Prog,
                         peer_ccb->call_info.currentRemoteName=,
                         ccb->call_info.currentLocalName=,
                         ccb->call_info.currentRemoteName=
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/ccsip_caps_ind: Negotiation not done yet:: Load DSP with preferred codec : g729r8, Bytes=20, payload: 18
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/ccsip_caps_ind: Set forking flag to 0x0
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sip_set_modem_caps: Disabling Modem Relay...
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sip_set_modem_caps: Negotiation NOT yet Done. Set the configured values and generate SDP Xcap list
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sip_set_modem_caps: nse payload = 100, ptru mode = 0, ptru-codec=0, redundancy=0, xid=1, relay=0, sprt-retry=12, latecncy=200, compres-dir=3, dict=1024, strnlen=32
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/ccsip_caps_ind: Load DSP with codec : g729r8, Bytes=20, payload = 18
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/ccsip_caps_ind: ccsip_caps_ind: ccb->pld.flags_ipip = 0x400003
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/ccsip_caps_ind: No video caps detected in the caps posted by peer leg
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/ccsip_caps_ind: Calling cc_api_caps_ack()
*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ack: Set forking flag to 0x0
*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0x400018, ccb->pld.flags_ipip 0x400001

*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/copy_channels:
callId 3473 size 240 ptr 0x681A79A0)
*Nov 25 22:24:59.865: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: 
*Nov 25 22:24:59.865: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 156)
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/ccsip_event_handler:
ccsip_event_handler: peer ID 3473 chans 0x681A79A0 event 156 flags 0x40201C 0x300 0x400003 data 0x681A79A0
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/ccsip_event_handler:
ccsip_event_handler: CC_EV_H245_OPEN_CHANNEL_IND: peer ID 3473  chans 0x681A79A0 event 156 flags 0x40201C 0x300 0x400003 data 0x681A79A0
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/ccsip_event_handler:
ccsip_event_handler: set event->type = SIPSPI_EV_CC_NEW_MEDIA!: peer ID 3473 chans 0x681A79A0 event 156 flags 0x40201C 0x300 0x400003 data 0x681A79A0
*Nov 25 22:24:59.865: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED
*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer: SIP2SIP, posting channel_ind to peer.

*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/ccsip_update_srtp_caps:  5009: Not Sending NULL SRTP CAPS to SIP LEG
*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
*Nov 25 22:24:59.865: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
*Nov 25 22:24:59.865: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
*Nov 25 22:24:59.865: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message

*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/HandleSIP1xxSessionProgress: ccsip_api_call_cut_progress returned: SIP_SUCCESS
*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/HandleSIP1xxSessionProgress: Transaction Complete. Lock on Facilities released.
*Nov 25 22:24:59.865: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 26
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_handle_channel_info:
CCSIP:callID 3472 ft: 1, inc 4, 200.36.172.3:26528, codec 12

*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_handle_channel_info:
CCSIP:callid 3472 state STATE_RECD_INVITE
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:
callid 3472, channels 0x681A79A0 caps 0x681F8750
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: Peer cap provided: callid = 3472, peer dtmf = 6
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/codec_found:
Codec to be matched: 12
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/codec_found: Not an exact match for G729 flavour, using g729br8
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sipSPIDtmfTranscoder: Return upon SCCP version 0
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_handle_channel_info: audio channel_ind
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_handle_channel_info: SIP2SIP, delayed media. flow-through

*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sipSPIIncomingCallSDP: SDP already there use old SDP and update media if needed
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sipSPIAddSDPPayloadAttributes:
max_event 15
*Nov 25 22:24:59.865: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729br8 codecbytes :20, ptime: 20
*Nov 25 22:24:59.865: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/ccsip_bridge: confID = 1687, srcCallID = 3472, dstCallID = 3473
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: -1/-1, new src/dest ccCallids: 3472/3473
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=-1, new streamcallid=3472
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/ccsip_bridge: xcoder_attached = 0, xmitFunc = 1669083472, ccb xmitFunc = 1669083472
*Nov 25 22:24:59.865: //3472/337E73D69EA8/SIP/Info/ccsip_bridge: ccsip_bridge: Delayed Media case
*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/ccsip_bridge: confID = 1687, srcCallID = 3473, dstCallID = 3472
*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: -1/-1, new src/dest ccCallids: 3473/3472
*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=3473, new streamcallid=3473
*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP
*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/ccsip_bridge: xcoder_attached = 0, xmitFunc = 1669083472, ccb xmitFunc = 1669083472
*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
*Nov 25 22:24:59.865: //3473/337E73D69EA8/SIP/Info/ccsip_bridge:
DTMF inb/oob iwf enabled 101
*Nov 25 22:24:59.865: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 4
*Nov 25 22:24:59.869: //3472/337E73D69EA8/SIP/Info/sipSPISendInviteResponse: Associated container=0x6CB7007C to Invite Response 183
*Nov 25 22:24:59.869: //3472/337E73D69EA8/SIP/Info/sentInviteResponse18x: Sent a 18x Response
*Nov 25 22:25:05.877: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [200.36.172.2]:5060
*Nov 25 22:25:05.877: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Nov 25 22:25:05.877: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPICheckResponse: INVITE response with no RSEQ - disable IS_REL1XX
*Nov 25 22:25:05.881: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIhandle200OKInvite: Transaction active. Facilities will be queued.
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIhandle200OKInvite: *** This ccb is the parent
*Nov 25 22:25:05.881: //3472/337E73D69EA8/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: 3472/3473, new src/dest ccCallids: 3472/3473
*Nov 25 22:25:05.881: //3472/337E73D69EA8/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=3472, new streamcallid=3472
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIProcessNotifyCallInfoHeader: Callinfo parsed - Destination url = <sip:200.36.172.2>, duration = 1000

*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIDoAudioNegotiation: Codec (g729br8) Negotiation Successful on Static Payload for m-line 1
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20
*Nov 25 22:25:05.881: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g729br8 ptime :20, codecbytes: 20
*Nov 25 22:25:05.881: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729br8 codecbytes :20, ptime: 20
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of full named event(NE) match in fmtp list of events.
*Nov 25 22:25:05.881: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sip_do_nse_negotiation: Remote NSE payload = local one = 0, Use it
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
*Nov 25 22:25:05.881: //3473/337E73D69EA8/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
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1
    payload_type=18, codec_bytes=20, codec=g729br8, dtmf_relay=rtp-nte
    stream_type=voice+dtmf (1), dest_ip_address=200.36.172.3, dest_port=26528
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 3473 peer 3472 flags 0x402401 state STATE_RECD_PROCEEDING
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 3473, sdp 0x69E8D690 channels 0x70EDAB34
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/copy_channels:
callId 3473 size 240 ptr 0x7094CD68)
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 18 mline 1
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g729br8
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/codec_found:
Codec to be matched: 12
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 12

*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: DO to EO case.If terminating side has sent more than one codec in the answer SDP, send only negotiated codec in ChannelInfo structure to peer leg.
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Report only negotiated codec (g729br8) to peer leg.
*Nov 25 22:25:05.881: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729br8 codecbytes :20, ptime: 20
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding negotiated codec 12 ptype 18 time 20,   bytes 20 as channel 0 mline 1 ss 1 200.36.172.3:26528
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 12

*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1

*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 3473 flags 0x100 state STATE_RECD_PROCEEDING
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/ccsip_update_srtp_caps:  5009: Not Sending NULL SRTP CAPS to SIP LEG
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIhandle200OKInvite: ccsip_api_call_connect_media returned: SIP_SUCCESS
*Nov 25 22:25:05.881: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
*Nov 25 22:25:05.881: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
*Nov 25 22:25:05.881: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message

*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIShrlCall: Check peer: 1000 for Shared-Line call, callid: 3473
*Nov 25 22:25:05.881: //3472/337E73D69EA8/SIP/Info/sipSPIShrlCall: Check peer: 6100 for Shared-Line call, callid: 3472
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPICreateAndStartRtpTimer:
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled.
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIhandle200OKInvite: ccsip_api_call_connected returned: SIP_SUCCESS
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPICallActive: Transaction Complete. Lock on Facilities released.
*Nov 25 22:25:05.881: //3473/337E73D69EA8/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
*Nov 25 22:25:05.881: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_call_connect: CCSIP_CALL_CONNECT: ccb ptr 70F17964

*Nov 25 22:25:05.885: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 6
*Nov 25 22:25:05.885: //3472/337E73D69EA8/SIP/Info/sipSPIAddCiscoGcid: Gcid value not set - not adding header.
*Nov 25 22:25:05.885: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_set_history_info_header: No HI header recvd from container
*Nov 25 22:25:05.885: //3472/337E73D69EA8/SIP/Info/preprocessConnect: Write sdp_info into msg_body
*Nov 25 22:25:05.885: //3472/337E73D69EA8/SIP/Info/preprocessConnect: Add msg_body into container 0x6CB6ED94
*Nov 25 22:25:05.885: //3472/337E73D69EA8/SIP/Info/sipSPIShrlGetInstanceInfo: Obtained the call instance 0 for non-shared-line '[1-9]...$' with callid: 3472
*Nov 25 22:25:05.885: //3472/337E73D69EA8/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat
*Nov 25 22:25:05.885: //3472/337E73D69EA8/SIP/Info/sipSPISendInviteResponse: Associated container=0x6CB6ED94 to Invite Response 200
*Nov 25 22:25:05.885: //3472/337E73D69EA8/SIP/Info/sentInviteResponse200: Sent 200Ok for Invite in state STATE_RECD_INVITE
*Nov 25 22:25:05.885: //-1/xxxxxxxxxxxx/SIP/Info/sentInviteResponse200: Transaction active. Facilities will be queued.
*Nov 25 22:25:06.301: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.0.70.254]:5060
*Nov 25 22:25:06.305: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Nov 25 22:25:06.305: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x70F17964
*Nov 25 22:25:06.305: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/act_sentsucc_new_message_request: Transaction Complete. Lock on Facilities released.
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/ccsip_api_request_answer: ccsip_api_request_answer.

*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/ccsip_api_request_answer: Entry
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPIDoAudioNegotiation: Codec (g729br8) Negotiation Successful on Static Payload for m-line 1
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20
*Nov 25 22:25:06.305: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g729br8 ptime :20, codecbytes: 20
*Nov 25 22:25:06.305: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729br8 codecbytes :20, ptime: 20
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved.
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events.
*Nov 25 22:25:06.305: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
*Nov 25 22:25:06.305: //3472/337E73D69EA8/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
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1
    payload_type=18, codec_bytes=20, codec=g729br8, dtmf_relay=rtp-nte
    stream_type=voice+dtmf (1), dest_ip_address=200.39.18.246, dest_port=17022
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPIProcessAckMedia: Media negotiation was not done earlier
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: Entry
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 3472 peer 3473 flags 0x400007 state STATE_SENT_SUCCESS
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 3472, sdp 0x69EBB3C8 channels 0x70F18C04
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/copy_channels:
callId 3472 size 240 ptr 0x69DA4470)
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 18 mline 1
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g729br8
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/codec_found:
Codec to be matched: 12
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 12

*Nov 25 22:25:06.305: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729br8 codecbytes :20, ptime: 20
*Nov 25 22:25:06.305: //3472/337E73D69EA8/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
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 12 ptype 18 time 20, bytes 20  as channel 0 mline 1 ss 1 200.39.18.246:17022
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 101 mline 1
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: setting ipip_caps DTMF to RFC2833: callid = 3472, dtmf = 6
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 12

*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1

*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 3472 flags 0x300 state STATE_SENT_SUCCESS
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer:
Report initial call media
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0xC0601E, ccb->pld.flags_ipip 0x400007

*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer: Post CAPS to peer.

*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ind: Entry
*Nov 25 22:25:06.305: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_caps_ind:
destCallID=3473, srcCallID=3472,
                         peer_ccb->call_info.currentLocalName=,
                         peer_ccb->call_info.currentRemoteName=,
                         ccb->call_info.currentLocalName=Administrador BD y Prog,
                         ccb->call_info.currentRemoteName=
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=3473, current_seq_num=0x1AAB
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=3473, current_seq_num=0x205E
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ind: Load DSP with negotiated codec: g729br8, Bytes=20
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ind: Set forking flag to 0x0
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_NTE_AND_OOB with rx payload = 101, tx payload = 101
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/sip_set_modem_caps: Disabling Modem Relay...
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled
*Nov 25 22:25:06.305: //3473/337E73D69EA8/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
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ind: Load DSP with codec : g729br8, Bytes=20, payload = 18
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ind: ccsip_caps_ind: ccb->pld.flags_ipip = 0x402401
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ind: No video caps detected in the caps posted by peer leg
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ind: Calling cc_api_caps_ack()
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/ccsip_caps_ack: Set forking flag to 0x0
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0xC0601E, ccb->pld.flags_ipip 0x400007

*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/copy_channels:
callId 3472 size 240 ptr 0x69DA4470)
*Nov 25 22:25:06.305: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: 
*Nov 25 22:25:06.305: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 156)
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/ccsip_event_handler:
ccsip_event_handler: peer ID 3472 chans 0x69DA4470 event 156 flags 0xC04018 0x100 0x402401 data 0x69DA4470
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/ccsip_event_handler:
ccsip_event_handler: CC_EV_H245_OPEN_CHANNEL_IND: peer ID 3472  chans 0x69DA4470 event 156 flags 0xC04018 0x100 0x402401 data 0x69DA4470
*Nov 25 22:25:06.305: //3473/337E73D69EA8/SIP/Info/ccsip_event_handler:
ccsip_event_handler: set event->type = SIPSPI_EV_CC_NEW_MEDIA!: peer ID 3472 chans 0x69DA4470 event 156 flags 0xC04018 0x100 0x402401 data 0x69DA4470
*Nov 25 22:25:06.305: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED
*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/sipSPI_ipip_report_media_to_peer: SIP2SIP, posting channel_ind to peer.

*Nov 25 22:25:06.305: //3472/337E73D69EA8/SIP/Info/ccsip_update_srtp_caps:  5009: Not Sending NULL SRTP CAPS to SIP LEG
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/sipSPICreateRtpSession: sess: 69ACB4F0 do_rtcp:1
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/sipSPIProcessMediaChanges: DSPDNLD Reqd is true. Call DoCapsInd
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=3472, current_seq_num=0x24EB
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=3472, current_seq_num=0x616
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/ccsip_do_caps_ind: Load DSP with codec: g729br8, Bytes=20
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_NTE_AND_OOB with rx payload = 101, tx payload = 101
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/sip_set_modem_caps: Disabling Modem Relay...
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled
*Nov 25 22:25:06.309: //3472/337E73D69EA8/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
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ind: Entry
*Nov 25 22:25:06.309: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_caps_ind:
destCallID=3473, srcCallID=3472,
                         peer_ccb->call_info.currentLocalName=,
                         peer_ccb->call_info.currentRemoteName=,
                         ccb->call_info.currentLocalName=Administrador BD y Prog,
                         ccb->call_info.currentRemoteName=
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=3473, current_seq_num=0x205E
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=3473, current_seq_num=0x205E
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ind: Load DSP with negotiated codec: g729br8, Bytes=20
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ind: Set forking flag to 0x0
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_NTE_AND_OOB with rx payload = 101, tx payload = 101
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/sip_set_modem_caps: Disabling Modem Relay...
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled
*Nov 25 22:25:06.309: //3473/337E73D69EA8/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
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ind: Load DSP with codec : g729br8, Bytes=20, payload = 18
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ind: ccsip_caps_ind: ccb->pld.flags_ipip = 0x402401
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ind: No video caps detected in the caps posted by peer leg
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/ccsip_caps_ind: Calling cc_api_caps_ack()
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/ccsip_caps_ack: Set forking flag to 0x0
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/sipSPIProcessRsvp: Entry
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/sipSPICreateAndStartRtpTimer:
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled.
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/ccsip_api_request_answer: ACK handling retval: SIP_SUCCESS
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/act_sentsucc_new_message_request: ccsip_api_request_answer return val:SIP_SUCCESS
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/sipSPIProcessHoldTimerForCall: Media IP Addr 200.39.18.246, RTCP Type 3
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
*Nov 25 22:25:06.309: //3472/337E73D69EA8/SIP/Info/ccsip_api_update_allowed: UPDATE(2) allowed
*Nov 25 22:25:06.309: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 26
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_handle_channel_info:
CCSIP:callID 3473 ft: 1, inc 0, 200.39.18.246:17022, codec 12

*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_handle_channel_info:
CCSIP:callid 3473 state STATE_ACTIVE
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_handle_channel_info: We are in Delayed Offer to Early Offer call flow and this is Early Offer Leg.
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_handle_channel_info: Negotiated codec on EO leg = g729br8, Negotiated codec on DO leg = g729br8
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_handle_channel_info: Don't send re-Invite on this leg.
*Nov 25 22:25:06.309: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_handle_channel_info: Audio Call - Turing off DO-EO Flag
*Nov 25 22:25:31.461: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.0.70.254]:5060
*Nov 25 22:25:31.461: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Nov 25 22:25:31.461: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Nov 25 22:25:31.461: //3472/337E73D69EA8/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x70F17964
*Nov 25 22:25:31.461: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
*Nov 25 22:25:31.461: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_set_release_source_for_peer: ownCallId[3472], src[2]
*Nov 25 22:25:31.461: //3472/337E73D69EA8/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
*Nov 25 22:25:31.461: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
*Nov 25 22:25:31.461: //3472/337E73D69EA8/SIP/Info/sipSPIInitiateDisconnect: Initiate call disconnect(16) for incoming call
*Nov 25 22:25:31.461: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
*Nov 25 22:25:31.461: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
*Nov 25 22:25:31.461: //3472/337E73D69EA8/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call.
*Nov 25 22:25:31.461: //3473/337E73D69EA8/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call.
*Nov 25 22:25:31.461: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 7
*Nov 25 22:25:31.461: //3472/337E73D69EA8/SIP/Info/sipSPISendByeResponse: Associated container=0x6CB6F99C to Bye Response
*Nov 25 22:25:31.461: //3472/337E73D69EA8/SIP/Info/sentByeResponse: Sent 200ok to the BYE, tearing down the call
*Nov 25 22:25:31.461: //3472/337E73D69EA8/SIP/Info/sipSPIIcpifUpdate: CallState: 4 Playout: 0 DiscTime:15710043 ConnTime 15707486
*Nov 25 22:25:31.465: //3472/337E73D69EA8/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id D90
*Nov 25 22:25:31.465: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 7
*Nov 25 22:25:31.465: //3473/337E73D69EA8/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
*Nov 25 22:25:31.465: //3473/337E73D69EA8/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
*Nov 25 22:25:31.465: //3473/337E73D69EA8/SIP/Info/sipSPISendBye: Associated container=0x6CB6DF7C to Bye
*Nov 25 22:25:31.465: //3473/337E73D69EA8/SIP/Info/sentByeDisconnecting: Sent Bye Request, starting DisconnectTimer
*Nov 25 22:25:31.645: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [200.36.172.2]:5060
*Nov 25 22:25:31.645: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Nov 25 22:25:31.645: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Nov 25 22:25:31.645: //3473/337E73D69EA8/SIP/Info/sipSPICheckResponse: non-INVITE response with no RSEQ - do not disable IS_REL1XX
*Nov 25 22:25:31.645: //3473/337E73D69EA8/SIP/Info/sipSPIIcpifUpdate: CallState: 4 Playout: 0 DiscTime:15710062 ConnTime 15707485
*Nov 25 22:25:31.645: //3473/337E73D69EA8/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id D91
*Nov 25 22:25:31.645: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[2408] removed.
*Nov 25 22:25:31.645: //3473/337E73D69EA8/SIP/Info/sipSPIUdeleteCcbFromUACTable: ****Deleting from UAC table.
*Nov 25 22:25:31.645: //3473/337E73D69EA8/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x70ED9894 key=338048E7-D94811DE-9EAE8264-5EE14E53@200.39.18.246
*Nov 25 22:25:31.645: //3473/337E73D69EA8/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
*Nov 25 22:25:31.645: //3473/337E73D69EA8/SIP/Info/ccsip_qos_cleanup: Entry
*Nov 25 22:25:31.645: //3473/337E73D69EA8/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
*Nov 25 22:25:31.645: //3473/337E73D69EA8/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 70ED9894
*Nov 25 22:25:31.645: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[2408]

12 Replies 12

gogasca
Level 10
Level 10

hi

//3473/337E73D69EA8/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_NTE_AND_OOB with rx payload = 101, tx payload = 101

looks like GW to provider looks ok

For CUCM Side r u using any xcoder or g729 directly to GW ?

can we get debug ccsip messages as well as CUCM traces?

Thanks a lot for your help

Here is the message log:

GW-iso-01#debug ccsip  messages
SIP Call messages tracing is enabled
GW-iso-01#
*Nov 24 11:37:51.457: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:405048181569600@200.39.18.246:5060 SIP/2.0
Date: Tue, 24 Nov 2009 13:40:02 GMT
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE,
NOTIFY, PUBLISH
From: "Administrador BD y Prog" <4504>;tag=79ee19d1-197e-4d5b-82
87-bb02fc56054c-19883280
Allow-Events: presence
Supported: 100rel,timer,replaces
Min-SE:  1800
Remote-Party-ID: "Administrador BD y Prog" <4504>;party=calling;
screen=yes;privacy=off
Content-Length: 0
User-Agent: Cisco-CUCM6.1
To: <405048181569600>
Contact: <4504>
Expires: 180
Call-ID: dc73aa80-b0b1e232-5c-fe46000a@10.0.70.254
Via: SIP/2.0/UDP 10.0.70.254:5060;branch=z9hG4bK3e57d13adb
CSeq: 101 INVITE
Session-Expires:  1800
Max-Forwards: 70


*Nov 24 11:37:51.457: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 422 Session Timer too small
Via: SIP/2.0/UDP 10.0.70.254:5060;branch=z9hG4bK3e57d13adb
From: "Administrador BD y Prog" <4504>;tag=79ee19d1-197e-4d5b-82
87-bb02fc56054c-19883280
To: <405048181569600>;tag=1E5D8A8-DF6
Date: Tue, 24 Nov 2009 11:37:51 GMT
Call-ID: dc73aa80-b0b1e232-5c-fe46000a@10.0.70.254
CSeq: 101 INVITE
Allow-Events: telephone-event
Min-SE:  2000
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0


*Nov 24 11:37:51.461: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:405048181569600@200.39.18.246:5060 SIP/2.0
Date: Tue, 24 Nov 2009 13:40:02 GMT
From: "Administrador BD y Prog" <4504>;tag=79ee19d1-197e-4d5b-82
87-bb02fc56054c-19883280
Allow-Events: presence
Content-Length: 0
To: <405048181569600>;tag=1E5D8A8-DF6
Call-ID: dc73aa80-b0b1e232-5c-fe46000a@10.0.70.254
Via: SIP/2.0/UDP 10.0.70.254:5060;branch=z9hG4bK3e57d13adb
CSeq: 101 ACK
Max-Forwards: 70


*Nov 24 11:37:51.461: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:405048181569600@200.39.18.246:5060 SIP/2.0
Date: Tue, 24 Nov 2009 13:40:02 GMT
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE,
NOTIFY, PUBLISH
From: "Administrador BD y Prog" <4504>;tag=79ee19d1-197e-4d5b-82
87-bb02fc56054c-19883280
Allow-Events: presence
Supported: 100rel,timer,replaces
Min-SE:  2000
Remote-Party-ID: "Administrador BD y Prog" <4504>;party=calling;
screen=yes;privacy=off
Content-Length: 0
User-Agent: Cisco-CUCM6.1
To: <405048181569600>
Contact: <4504>
Expires: 180
Call-ID: dc73aa80-b0b1e232-5d-fe46000a@10.0.70.254
Via: SIP/2.0/UDP 10.0.70.254:5060;branch=z9hG4bK3f3c8ad928
CSeq: 101 INVITE
Session-Expires:  2000
Max-Forwards: 70


*Nov 24 11:37:51.469: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.0.70.254:5060;branch=z9hG4bK3f3c8ad928
From: "Administrador BD y Prog" <4504>;tag=79ee19d1-197e-4d5b-82
87-bb02fc56054c-19883280
To: <405048181569600>
Date: Tue, 24 Nov 2009 11:37:51 GMT
Call-ID: dc73aa80-b0b1e232-5d-fe46000a@10.0.70.254
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0


*Nov 24 11:37:51.473: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:405048181569600@200.39.13.4:5060 SIP/2.0
Via: SIP/2.0/UDP 200.39.18.246:5060;branch=z9hG4bK1BFE28
From: "Administrador BD y Prog" <4504>;tag=1E5D8B4-2658
To: <405048181569600>
Date: Tue, 24 Nov 2009 11:37:51 GMT
Call-ID: A1EBC039-D82411DE-89028264-5EE14E53@200.39.18.246
Cisco-Guid: 2716501841-3626242526-2298249828-1591823955
User-Agent: Cisco-SIPGateway/IOS-12.x
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIF
Y, INFO, REGISTER
CSeq: 101 INVITE
Timestamp: 1259062671
Contact: <4504>
Call-Info: <200.39.18.246:5060>;method="NOTIFY;Event=telephone-event;Duratio
n=2000"
History-Info: <405048181569600>;index=1
Expires: 180
Allow-Events: telephone-event
Max-Forwards: 69
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 286

v=0
o=CiscoSystemsSIP-GW-UserAgent 7718 3956 IN IP4 200.39.18.246
s=SIP Call
c=IN IP4 200.39.18.246
t=0 0
m=audio 18766 RTP/AVP 18 0 101
c=IN IP4 200.39.18.246
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=yes
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

*Nov 24 11:37:51.485: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 200.39.18.246:5060;branch=z9hG4bK1BFE28
From: "Administrador BD y Prog" <4504>;tag=1E5D8B4-2658
To: <405048181569600>
Call-ID: A1EBC039-D82411DE-89028264-5EE14E53@200.39.18.246
CSeq: 101 INVITE
Content-Length: 0


*Nov 24 11:37:51.913: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 200.39.18.246:5060;branch=z9hG4bK1BFE28
To: <405048181569600>;tag=3468051266-75638
From: "Administrador BD y Prog" <4504>;tag=1E5D8B4-2658
Call-ID: A1EBC039-D82411DE-89028264-5EE14E53@200.39.18.246
CSeq: 101 INVITE
Allow: INVITE, BYE, OPTIONS, CANCEL, ACK, REGISTER, NOTIFY, INFO, REFER, SUBSCRI
BE, PRACK, UPDATE
Contact: <405048181569600>
Call-Info: <200.39.13.4>;method="NOTIFY;Event=telephone-event;Duration=2000"
Content-Type: application/sdp
Content-Length: 165

v=0
o=MTY-BMSW-01D 2147483647 2147483647 IN IP4 200.39.13.4
s=sip call
c=IN IP4 200.39.13.5
t=0 0
m=audio 31726 RTP/AVP 18 0
a=ptime:20
a=fmtp:18 annexb=yes

*Nov 24 11:37:51.921: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 10.0.70.254:5060;branch=z9hG4bK3f3c8ad928
From: "Administrador BD y Prog" <4504>;tag=79ee19d1-197e-4d5b-82
87-bb02fc56054c-19883280
To: <405048181569600>;tag=1E5DA74-6AE
Date: Tue, 24 Nov 2009 11:37:51 GMT
Call-ID: dc73aa80-b0b1e232-5d-fe46000a@10.0.70.254
CSeq: 101 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIF
Y, INFO, REGISTER
Allow-Events: telephone-event
Contact: <405048181569600>
Supported: sdp-anat
Server: Cisco-SIPGateway/IOS-12.x
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 297

v=0
o=CiscoSystemsSIP-GW-UserAgent 2171 718 IN IP4 200.39.18.246
s=SIP Call
c=IN IP4 200.39.18.246
t=0 0
m=audio 18722 RTP/AVP 18 101 19
c=IN IP4 200.39.18.246
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=yes
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:19 CN/8000
a=ptime:20

*Nov 24 11:37:57.773: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 200.39.18.246:5060;branch=z9hG4bK1BFE28
To: <405048181569600>;tag=3468051266-75638
From: "Administrador BD y Prog" <4504>;tag=1E5D8B4-2658
Call-ID: A1EBC039-D82411DE-89028264-5EE14E53@200.39.18.246
CSeq: 101 INVITE
Allow: INVITE, BYE, OPTIONS, CANCEL, ACK, REGISTER, NOTIFY, INFO, REFER, SUBSCRI
BE, PRACK, UPDATE
Contact: <405048181569600>
Call-Info: <200.39.18.246:5060>;method="NOTIFY;Event=telephone-event;Duratio
n=2000"
Content-Type: application/sdp
Content-Length: 165

v=0
o=MTY-BMSW-01D 2147483647 2147483647 IN IP4 200.39.13.4
s=sip call
c=IN IP4 200.39.13.5
t=0 0
m=audio 31726 RTP/AVP 18 0
a=ptime:20
a=fmtp:18 annexb=yes

*Nov 24 11:37:57.777: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
ACK sip:405048181569600@200.39.13.4:5060 SIP/2.0
Via: SIP/2.0/UDP 200.39.18.246:5060;branch=z9hG4bK1C0E83
From: "Administrador BD y Prog" <4504>;tag=1E5D8B4-2658
To: <405048181569600>;tag=3468051266-75638
Date: Tue, 24 Nov 2009 11:37:51 GMT
Call-ID: A1EBC039-D82411DE-89028264-5EE14E53@200.39.18.246
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event
Content-Length: 0


*Nov 24 11:37:57.777: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.70.254:5060;branch=z9hG4bK3f3c8ad928
From: "Administrador BD y Prog" <4504>;tag=79ee19d1-197e-4d5b-82
87-bb02fc56054c-19883280
To: <405048181569600>;tag=1E5DA74-6AE
Date: Tue, 24 Nov 2009 11:37:51 GMT
Call-ID: dc73aa80-b0b1e232-5d-fe46000a@10.0.70.254
CSeq: 101 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIF
Y, INFO, REGISTER
Allow-Events: telephone-event
Contact: <405048181569600>
Supported: replaces
Supported: sdp-anat
Server: Cisco-SIPGateway/IOS-12.x
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 297

v=0
o=CiscoSystemsSIP-GW-UserAgent 2171 718 IN IP4 200.39.18.246
s=SIP Call
c=IN IP4 200.39.18.246
t=0 0
m=audio 18722 RTP/AVP 18 101 19
c=IN IP4 200.39.18.246
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=yes
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:19 CN/8000
a=ptime:20

*Nov 24 11:37:57.793: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:405048181569600@200.39.18.246:5060 SIP/2.0
Date: Tue, 24 Nov 2009 13:40:02 GMT
From: "Administrador BD y Prog" <4504>;tag=79ee19d1-197e-4d5b-82
87-bb02fc56054c-19883280
Allow-Events: presence
Content-Length: 214
To: <405048181569600>;tag=1E5DA74-6AE
Content-Type: application/sdp
Call-ID: dc73aa80-b0b1e232-5d-fe46000a@10.0.70.254
Via: SIP/2.0/UDP 10.0.70.254:5060;branch=z9hG4bK404b01fa06
CSeq: 101 ACK
Max-Forwards: 70

v=0
o=CiscoSystemsCCM-SIP 2000 2 IN IP4 10.0.70.254
s=SIP Call
c=IN IP4 200.39.18.246
t=0 0
m=audio 18818 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

*Nov 24 11:38:08.521: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
BYE sip:405048181569600@200.39.18.246:5060 SIP/2.0
Date: Tue, 24 Nov 2009 13:40:02 GMT
From: "Administrador BD y Prog" <4504>;tag=79ee19d1-197e-4d5b-82
87-bb02fc56054c-19883280
Content-Length: 0
User-Agent: Cisco-CUCM6.1
To: <405048181569600>;tag=1E5DA74-6AE
Call-ID: dc73aa80-b0b1e232-5d-fe46000a@10.0.70.254
Via: SIP/2.0/UDP 10.0.70.254:5060;branch=z9hG4bK417d5ca93e
CSeq: 102 BYE
Max-Forwards: 70


*Nov 24 11:38:08.525: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.70.254:5060;branch=z9hG4bK417d5ca93e
From: "Administrador BD y Prog" <4504>;tag=79ee19d1-197e-4d5b-82
87-bb02fc56054c-19883280
To: <405048181569600>;tag=1E5DA74-6AE
Date: Tue, 24 Nov 2009 11:38:08 GMT
Call-ID: dc73aa80-b0b1e232-5d-fe46000a@10.0.70.254
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 102 BYE
Reason: Q.850;cause=16
Content-Length: 0


*Nov 24 11:38:08.525: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
BYE sip:405048181569600@200.39.13.4:5060 SIP/2.0
Via: SIP/2.0/UDP 200.39.18.246:5060;branch=z9hG4bK1C1A52
From: "Administrador BD y Prog" <4504>;tag=1E5D8B4-2658
To: <405048181569600>;tag=3468051266-75638
Date: Tue, 24 Nov 2009 11:37:51 GMT
Call-ID: A1EBC039-D82411DE-89028264-5EE14E53@200.39.18.246
User-Agent: Cisco-SIPGateway/IOS-12.x
Max-Forwards: 70
Timestamp: 1259062688
CSeq: 102 BYE
Reason: Q.850;cause=16
Content-Length: 0


*Nov 24 11:38:08.557: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 200.39.18.246:5060;branch=z9hG4bK1C1A52
To: <405048181569600>;tag=3468051266-75638
From: "Administrador BD y Prog" <4504>;tag=1E5D8B4-2658
Call-ID: A1EBC039-D82411DE-89028264-5EE14E53@200.39.18.246
CSeq: 102 BYE
Allow: INVITE, BYE, OPTIONS, CANCEL, ACK, REGISTER, NOTIFY, INFO, REFER, SUBSCRI
BE, PRACK, UPDATE
Contact: <405048181569600>
Content-Length: 0

Actually Movistar told me that they didnt have any Cisco client connected to his Softswitch, they got a Nortel.


And they said that  settings in Nortel  are OK.  But we still having this problem.

I will appreciate all your help.

Best Regards.

VOIP RTP Debug - ALL debugging is on
cme-isolux-01#
*Nov 26 15:27:21.596: voip_rtp_create_session idb tableid is 0,session table id is 0
*Nov 26 15:27:21.596: voip_rtp_create_session: callID=13975, dstCallID=-1 laddr=200.39.18.246, lport=18484,raddr=0.0.0.0, rport=0, type=2, sig_tos=3, ip_tos=5
*Nov 26 15:27:21.596:  voip_rtp_update_xmit_info
*Nov 26 15:27:21.596:  voip_rtp_update_xmit_info, dstvdbptr: 0, dstCallID -1, gccb: 70316660, xmitFunc 0,context 0
*Nov 26 15:27:21.596:  voip_rtp_update_xmit_info Context is NULL, exit
*Nov 26 15:27:21.596: voip_rtp_update_cisco_payloads:
*Nov 26 15:27:21.596: voip_rtp_update_cisco_payloads: The updated cisco reserved payload types are:
         cisco_codec_fax_pt = 96, cisco_codec_fax_ack_pt = 97,
         cisco_rtp_dtmf_relay_pt = 121, cisco_fax_relay_pt = 122,
         cisco_cas_pt = 123, cisco_clear_channel_pt = 125,
         cisco_rtp_type_annex_B = 123, cisco_lmr_tone_pt = 0,
         cisco_nte_tone_pt = 0
*Nov 26 15:27:21.596: voip_rtp_set_non_rtp_call: Non-RTP call end
*Nov 26 15:27:22.136: RTP(62565): fs rx s=0.0.0.0(0), d=200.39.18.246(18484), pt=18, ts=D4A24380, ssrc=357AF4AD, marker=0
*Nov 26 15:27:22.140: voip_rtp_exchange_context_info
*Nov 26 15:27:22.144: voip_rtp_exchange_context_info gccb not found, context is NULL
*Nov 26 15:27:22.144: IPIPGW: voip_rtp_update_callinfo, IP-IP DETECTED, in=3, out=3
*Nov 26 15:27:22.144:  Error:voip_rtp_get_gccb: no such gccb

*Nov 26 15:27:22.144: voip_rtp_update_callinfo: RTCP enabled
*Nov 26 15:27:22.144: voip_rtp_update_local_ssrc srtp: 0 CallID: 13975 dstCallID: 13974 new ssrc: 0x141E12F6
*Nov 26 15:27:22.144: voip_rtcp_get_cname: cname=0.0.0@200.39.18.246
*Nov 26 15:27:22.144: voip_rtp_update_callinfo: RTP address/port changes 0:0->C824AC03:6F8C
*Nov 26 15:27:22.144: voip_rtp_update_callinfo: first_pak=TRUE, new_ssrc=0, type=3
*Nov 26 15:27:22.144:  voip_rtp_update_xmit_info
*Nov 26 15:27:22.144:  voip_rtp_update_xmit_info, dstvdbptr: 68FDB7C4, dstCallID 13974, gccb: 70316660, xmitFunc 637C3150,context 0
*Nov 26 15:27:22.144:  voip_rtp_update_xmit_info Context is NULL, exit
*Nov 26 15:27:22.144: voip_rtp_set_non_rtp_call: Non-RTP call end
*Nov 26 15:27:22.144: voip_rtcp_start_session:
*Nov 26 15:27:22.144: voip_rtcp_start_session: start session
*Nov 26 15:27:22.164: RTP(62566): ps rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A24470, ssrc=357AF4AD, marker=0
*Nov 26 15:27:22.164: voip_rtp_xmit:no context
*Nov 26 15:27:22.404: RTP(62567): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A24BA0, ssrc=357AF4AD, marker=1
*Nov 26 15:27:22.404: voip_rtp_xmit:no context
*Nov 26 15:27:22.424: RTP(62568): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A24C40, ssrc=357AF4AD, marker=0
*Nov 26 15:27:22.424: voip_rtp_xmit:no context
*Nov 26 15:27:22.424: RTP(62569): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A24C90, ssrc=357AF4AD, marker=0
*Nov 26 15:27:22.424: voip_rtp_xmit:no context
*Nov 26 15:27:22.456: RTP(62570): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A24D80, ssrc=357AF4AD, marker=0
*Nov 26 15:27:22.456: voip_rtp_xmit:no context
*Nov 26 15:27:22.636:  Error:voip_rtp_get_gccb: no such gccb

*Nov 26 15:27:23.456: RTP(62571): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A26CC0, ssrc=357AF4AD, marker=0
*Nov 26 15:27:23.456: voip_rtp_xmit:no context
*Nov 26 15:27:23.636:  Error:voip_rtp_get_gccb: no such gccb

*Nov 26 15:27:24.456: RTP(62572): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A28C00, ssrc=357AF4AD, marker=0
*Nov 26 15:27:24.456: voip_rtp_xmit:no context
*Nov 26 15:27:24.636:  Error:voip_rtp_get_gccb: no such gccb

*Nov 26 15:27:25.424: RTP(62573): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A2AA00, ssrc=357AF4AD, marker=1
*Nov 26 15:27:25.424: voip_rtp_xmit:no context
*Nov 26 15:27:25.444: RTP(62574): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A2AAA0, ssrc=357AF4AD, marker=0
*Nov 26 15:27:25.444: voip_rtp_xmit:no context
*Nov 26 15:27:25.456: RTP(62575): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A2AB40, ssrc=357AF4AD, marker=0
*Nov 26 15:27:25.456: voip_rtp_xmit:no context
*Nov 26 15:27:25.484: RTP(62576): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A2AC30, ssrc=357AF4AD, marker=0
*Nov 26 15:27:25.484: voip_rtp_xmit:no context
*Nov 26 15:27:25.636:  Error:voip_rtp_get_gccb: no such gccb

*Nov 26 15:27:25.884: RTP(62577): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A2B8B0, ssrc=357AF4AD, marker=0
*Nov 26 15:27:25.884: voip_rtp_xmit:no context
*Nov 26 15:27:25.916: RTP(62578): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A2B9A0, ssrc=357AF4AD, marker=0
*Nov 26 15:27:25.916: voip_rtp_xmit:no context
*Nov 26 15:27:25.944: RTP(62579): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A2BA90, ssrc=357AF4AD, marker=0
*Nov 26 15:27:25.944: voip_rtp_xmit:no context
*Nov 26 15:27:26.636:  Error:voip_rtp_get_gccb: no such gccb

*Nov 26 15:27:26.944: RTP(62580): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A2D9D0, ssrc=357AF4AD, marker=0
*Nov 26 15:27:26.944: voip_rtp_xmit:no context
*Nov 26 15:27:27.536: RTP(62581): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A2EBF0, ssrc=357AF4AD, marker=1
*Nov 26 15:27:27.536: voip_rtp_xmit:no context
*Nov 26 15:27:27.556: RTP(62582): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A2EC90, ssrc=357AF4AD, marker=0
*Nov 26 15:27:27.556: voip_rtp_xmit:no context
*Nov 26 15:27:27.576: RTP(62583): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A2ED30, ssrc=357AF4AD, marker=0
*Nov 26 15:27:27.576: voip_rtp_xmit:no context
*Nov 26 15:27:27.596: RTP(62584): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A2EDD0, ssrc=357AF4AD, marker=0
*Nov 26 15:27:27.596: voip_rtp_xmit:no context
*Nov 26 15:27:27.616: RTP(62585): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A2EE70, ssrc=357AF4AD, marker=0
*Nov 26 15:27:27.616: voip_rtp_xmit:no context
*Nov 26 15:27:27.636: RTP(62586): fs rx s=200.36.172.3(28556), d=200.39.18.246(18484), pt=18, ts=D4A2EF10, ssrc=357AF4AD, marker=0
*Nov 26 15:27:27.636: voip_rtp_xmit:no context
*Nov 26 15:27:27.636:  Error:voip_rtp_get_gccb: no such gccb

I don't know if this will help, but I have had cRTP impact NTE before in a very similar situation - everything else worked fine but DTMF.  Can you check the WAN configuration and see if it is turned on?

HTH

Art Sandborgh

I had an almost identical problem with a SIP trunk to Unity. It ended up being G.729b was being negotiated. There is a service parameter on UCM "Strip G.729 Annex B (Silence Suppression) from Capabilities" that you can use to prevent this.

Hi,

Thanks for your answers guys,

This is my Serial settings:

interface Serial0/0/0:1
ip address 200.39.23.222 255.255.255.252
ip virtual-reassembly
crypto map SDM_CMAP_1

I did what Jonathan said but,  if I change that parameter i  not able to make calls.

This is very odd.  This is my debug of DTMF, and  the gateway its reciving and sending the tones:

*Nov 30 18:25:05.100:          s=VoIP d=DSP payload 0x65 ssrc 0x4F8596F8 sequence 0x89F timestamp 0x17B150
*Nov 30 18:25:05.100:  << Pt:101    Evt:1       Pkt:0A 00 A0
*Nov 30 18:25:05.100:          s=DSP d=VoIP payload 0x65 ssrc 0x4F8596F8 sequence 0x89F timestamp 0x17B150
*Nov 30 18:25:05.100:          Pt:101    Evt:1       Pkt:0A 00 A0  >>
*Nov 30 18:25:05.104:          s=VoIP d=DSP payload 0x65 ssrc 0x4F8596F8 sequence 0x89F timestamp 0x17B150
*Nov 30 18:25:05.104:  << Pt:101    Evt:1       Pkt:0A 00 A0
*Nov 30 18:25:05.104:          s=DSP d=VoIP payload 0x65 ssrc 0x4F8596F8 sequence 0x89F timestamp 0x17B150
*Nov 30 18:25:05.104:          Pt:101    Evt:1       Pkt:0A 00 A0  >>
*Nov 30 18:25:05.108:          s=VoIP d=DSP payload 0x65 ssrc 0x4F8596F8 sequence 0x89F timestamp 0x17B150
*Nov 30 18:25:05.108:  << Pt:101    Evt:1       Pkt:0A 00 A0
*Nov 30 18:25:05.108:          s=DSP d=VoIP payload 0x65 ssrc 0x4F8596F8 sequence 0x89F timestamp 0x17B150
*Nov 30 18:25:05.108:          Pt:101    Evt:1       Pkt:0A 00 A0  >>
*Nov 30 18:25:05.120:          s=VoIP d=DSP payload 0x65 ssrc 0x4F8596F8 sequence 0x8A0 timestamp 0x17B150
*Nov 30 18:25:05.120:  << Pt:101    Evt:1       Pkt:0A 01 40
*Nov 30 18:25:05.120:          s=DSP d=VoIP payload 0x65 ssrc 0x4F8596F8 sequence 0x8A0 timestamp 0x17B150
*Nov 30 18:25:05.120:          Pt:101    Evt:1       Pkt:0A 01 40  >>
*Nov 30 18:25:05.140:          s=VoIP d=DSP payload 0x65 ssrc 0x4F8596F8 sequence 0x8A1 timestamp 0x17B150
*Nov 30 18:25:05.140:  << Pt:101    Evt:1       Pkt:0A 01 E0
*Nov 30 18:25:05.140:          s=DSP d=VoIP payload 0x65 ssrc 0x4F8596F8 sequence 0x8A1 timestamp 0x17B150
*Nov 30 18:25:05.140:          Pt:101    Evt:1       Pkt:0A 01 E0  >>
*Nov 30 18:25:05.160:          s=VoIP d=DSP payload 0x65 ssrc 0x4F8596F8 sequence 0x8A2 timestamp 0x17B150
*Nov 30 18:25:05.160:  << Pt:101    Evt:1       Pkt:0A 02 80
*Nov 30 18:25:05.160:          s=DSP d=VoIP payload 0x65 ssrc 0x4F8596F8 sequence 0x8A2 timestamp 0x17B150
*Nov 30 18:25:05.160:          Pt:101    Evt:1       Pkt:0A 02 80  >>
*Nov 30 18:25:05.180:          s=VoIP d=DSP payload 0x65 ssrc 0x4F8596F8 sequence 0x8A3 timestamp 0x17B150
*Nov 30 18:25:05.180:  << Pt:101    Evt:1       Pkt:8A 03 20
*Nov 30 18:25:05.180:          s=DSP d=VoIP payload 0x65 ssrc 0x4F8596F8 sequence 0x8A3 timestamp 0x17B150
*Nov 30 18:25:05.180:          Pt:101    Evt:1       Pkt:8A 03 20  >>
*Nov 30 18:25:05.184:          s=VoIP d=DSP payload 0x65 ssrc 0x4F8596F8 sequence 0x8A3 timestamp 0x17B150
*Nov 30 18:25:05.184:  << Pt:101    Evt:1       Pkt:8A 03 20
*Nov 30 18:25:05.184:          s=DSP d=VoIP payload 0x65 ssrc 0x4F8596F8 sequence 0x8A3 timestamp 0x17B150
*Nov 30 18:25:05.184:          Pt:101    Evt:1       Pkt:8A 03 20  >>
*Nov 30 18:25:05.188:          s=VoIP d=DSP payload 0x65 ssrc 0x4F8596F8 sequence 0x8A3 timestamp 0x17B150
*Nov 30 18:25:05.188:  << Pt:101    Evt:1       Pkt:8A 03 20
*Nov 30 18:25:05.188:          s=DSP d=VoIP payload 0x65 ssrc 0x4F8596F8 sequence 0x8A3 timestamp 0x17B150
*Nov 30 18:25:05.188:          Pt:101    Evt:1       Pkt:8A 03 20  >>

Thanks in Advance

What does the voice-class on IOS look like?

voice-class sip g729 annexb-all

If you strip annex B support from UCM and IOS (or the provider) is requiring it, the call will definitely fail.

voice service voip
allow-connections h323 to h323
allow-connections h323 to sip
allow-connections sip to h323
allow-connections sip to sip
no supplementary-service sip moved-temporarily
no supplementary-service sip refer
fax protocol t38 ls-redundancy 0 hs-redundancy 0 fallback pass-through g711ulaw
h323
sip
  bind control source-interface Loopback0
  bind media source-interface Loopback0
  no update-callerid
  early-offer forced
  midcall-signaling passthru
  g729 annexb-all

So that is not a voice-class. That's your CUBE configuration. Anyways, it appears that you have G.729b specified on IOS. You'll need to allow G.729r8 or G.729ar8 instead. If G.729br8 or G.729abr8 are configured, IOS will only advertise the annex B varient which is why your calls failed once you stripped this support on UCM.  You need to fix your IOS config and try again.

Also, in case it doesn't make sense why yet: annex B introduced silence suppression to G.729. If you're sending the DTMF digits as a media payload packet and not an out of band signaling command such as KPML, silence suppression will stomp all over your DTMF media.

Ok.

Im lost this is my voice-class

voice class codec 2
codec preference 1 g729r8
codec preference 2 g729br8
codec preference 3 g711ulaw
codec preference 4 g711alaw
codec preference 5 gsmamr-nb

OUT

dial-peer voice 1000 voip
description Telefonica
destination-pattern 40504.T
signaling forward conditional
voice-class codec 2
voice-class sip g729 annexb-all
voice-class sip early-offer forced
session protocol sipv2
session target ipv4:200.36.172.2
dtmf-relay rtp-nte digit-drop
fax-relay sg3-to-g3
fax rate 9600 bytes 48
fax protocol t38 ls-redundancy 0 hs-redundancy 0 fallback pass-through g711ulaw
no vad

IN

dial-peer voice 6100 voip
destination-pattern [1-9]...$
signaling forward conditional
voice-class codec 2
voice-class sip g729 annexb-all
voice-class sip early-offer forced
session protocol sipv2
session target ipv4:10.0.70.254
incoming called-number 91..
dtmf-relay rtp-nte
fax-relay sg3-to-g3
fax rate 14400
fax protocol t38 ls-redundancy 0 hs-redundancy 0 fallback pass-through g711ulaw

Please tell me what i need to do,  I have not experince with SIP.

Robert.

Jonathan,

I had changed but it is the same, when i  choose  Strip G.729 Annex B (Silence Suppression)  True, i  couldnt   make calls to SIp Provider.

This is my voice-class   now:

voice class codec 2
codec preference 1 g729br8
codec preference 3 g711ulaw
codec preference 4 g711alaw
codec preference 5 gsmamr-nb

Best Regads.

Robert.

Getting Started

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