SIP trunk early offer - Page 3

j.huizinga · ‎06-14-2012

Hi,

We have configured a trunk with a provider using CUBE.

Callmanager--------CUBE--------Provider

The provider wants early offer and G729r8

So we configured a SIP trunk with a device pool/region so that only g729 is allowed between SIP trunk and the rest.

We have configured an IOS MTP resource, and this is registered on callmanager:

!

dspfarm profile 2 mtp

codec g729r8

maximum sessions software 20

associate application SCCP

!

The mtp resource is assign to the trunk using MR-list and MR-group

The trunk has MTP enabled with "MTP prefered Codec" G729b/G729ab

On CUBE we enable "deb ccsip mess" and we see the invite comming from callmanager, but without attached SDP

What must be done to make callmanager use early-offer?

Thanks for the help,

Jan

Vivek Batra · ‎08-25-2015

We need to see the SIP traces to identify where the problem is.

Mukesh Kumar · ‎08-25-2015

Hello Vivek,

Below is the config:

version 15.1
service timestamps debug datetime msec
service timestamps log datetime msec
service password-encryption
!
hostname Cisco
!
boot-start-marker
boot-end-marker
!
!
card type t1 0 0
!
no aaa new-model
!

network-clock-participate wic 0
!
dot11 syslog
ip source-route
!
!
ip cef
!
!
!
ip name-server 8.8.8.8
ip name-server 4.2.2.2
no ipv6 cef
!
multilink bundle-name authenticated
!
!
!
!
isdn switch-type primary-ni
!
!
!
voice service voip
ip address trusted list
ipv4 70.70.1.2
allow-connections h323 to h323
allow-connections h323 to sip
allow-connections sip to h323
allow-connections sip to sip
fax protocol t38 version 0 ls-redundancy 0 hs-redundancy 0 fallback none
sip
!
voice class codec 1
codec preference 1 g711ulaw
!
!
!
!
voice translation-rule 11
rule 1 /^$.......$$/ /500\1/
!
voice translation-rule 12
rule 1 /^.*/ /8547845654/
!
!
voice translation-profile SIP-CALL
translate calling 12
translate called 11
!
!
voice-card 0
dsp services dspfarm
!
crypto pki token default removal timeout 0
!
!
!
!
!
redundancy
!
!
controller T1 0/0/0
clock source internal
cablelength long 0db
pri-group timeslots 1-24
!
!
!
interface GigabitEthernet0/0
ip address 40.40.1.5 255.255.255.252
ip flow ingress
ip flow egress
duplex full
speed 100
!
!
interface Serial0/0/0:23
no ip address
ip flow ingress
encapsulation hdlc
isdn switch-type primary-ni
isdn protocol-emulate network
isdn incoming-voice voice
isdn outgoing display-ie
isdn outgoing ie redirecting-number
no cdp enable
!
ip forward-protocol nd
no ip http server
no ip http secure-server
!
ip route 0.0.0.0 0.0.0.0 40.40.1.6
!

!
control-plane
!
!
voice-port 0/0/0:23
!
!
!
mgcp profile default
!
!
dial-peer voice 100 pots
incoming called-number .
direct-inward-dial
!
dial-peer voice 20 voip
translation-profile outgoing SIP-CALL
preference 3
destination-pattern .T
session protocol sipv2
session target ipv4:70.70.1.2
session transport udp
incoming called-number .
voice-class codec 1
dtmf-relay sip-notify rtp-nte
no vad
!
dial-peer voice 10 pots
destination-pattern 8547845655$
forward-digits 4
port 0/0/0:23
!
dial-peer voice 11 pots
destination-pattern 8547845656$
forward-digits 4
port 0/0/0:23
!

!
sip-ua
credentials username 8547845654 password Cisco realm abc.sip.com
authentication username 8547845654 password Cisco realm abc.sip.com
retry invite 3
retry register 3
timers register 150
registrar dns:abc.sip.com expires 200
sip-server dns:abc.sip.com
!
!
!
!
line con 0
login local
line aux 0
login local
line vty 0 4
login local
transport input all
!
scheduler allocate 20000 1000
end

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

show controllers t1
T1 0/0/0 is up.
Applique type is Channelized T1
Cablelength is long 0db
No alarms detected.
alarm-trigger is not set
Soaking time: 3, Clearance time: 10
AIS State:Clear LOS State:Clear LOF State:Clear
Version info Firmware: 20100222, FPGA: 13, spm_count = 0
Framing is ESF, Line Code is B8ZS, Clock Source is Internal.
CRC Threshold is 320. Reported from firmware is 320.
Data in current interval (832 seconds elapsed):
0 Line Code Violations, 0 Path Code Violations
0 Slip Secs, 0 Fr Loss Secs, 0 Line Err Secs, 0 Degraded Mins
0 Errored Secs, 0 Bursty Err Secs, 0 Severely Err Secs, 0 Unavail Secs
Total Data (last 55 15 minute intervals):
0 Line Code Violations, 0 Path Code Violations,
174 Slip Secs, 0 Fr Loss Secs, 0 Line Err Secs, 0 Degraded Mins,
174 Errored Secs, 0 Bursty Err Secs, 0 Severely Err Secs, 120 Unavail Secs

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

We have taken debug ccsip all and below is the output,

debug ccsip calls
SIP Call statistics tracing is enabled

Aug 5 13:28:53.499: //7692/BAFC65BE800F/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x4B985B90
State of The Call : STATE_ACTIVE
TCP Sockets Used : NO
Calling Number : 8547845654
Called Number : 7248454145
Source IP Address (Sig ): 40.40.1.5
Destn SIP Req Addr:Port : 70.70.1.2:5060
Destn SIP Resp Addr:Port : 70.70.1.2:5060
Destination Name : abc.sip.com

Aug 5 13:28:53.503: //7692/BAFC65BE800F/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): 40.40.1.5
Source IP Port (Media): 18756
Destn IP Address (Media): 70.70.1.2
Destn IP Port (Media): 10872
Orig Destn IP Address:Port (Media): [ - ]:0

Aug 5 13:28:53.507: %ISDN-6-CONNECT: Interface Serial0/0/0:22 is now connected to 7248454145 N/A
Aug 5 13:28:53.575: %ISDN-6-DISCONNECT: Interface Serial0/0/0:22 disconnected from unknown , call lasted 0 seconds
Aug 5 13:28:53.683: //7692/BAFC65BE800F/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x4B985B90
State of The Call : STATE_DEAD
TCP Sockets Used : NO
Calling Number : 8547845654
Called Number : 7248454145
Source IP Address (Sig ): 40.40.1.5
Destn SIP Req Addr:Port : 70.70.1.2:5060
Destn SIP Resp Addr:Port : 70.70.1.2:5060
Destination Name : abc.sip.com

Aug 5 13:28:53.683: //7692/BAFC65BE800F/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): 40.40.1.5
Source IP Port (Media): 18756
Destn IP Address (Media): 70.70.1.2
Destn IP Port (Media): 10872
Orig Destn IP Address:Port (Media): [ - ]:0

Aug 5 13:28:53.683: //7692/BAFC65BE800F/SIP/Call/sipSPICallInfo:
Disconnect Cause (CC) : 16
Disconnect Cause (SIP) : 200

Aug 5 13:31:50.267: //7776/1DBED30688A3/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x4B98B588
State of The Call : STATE_DEAD
TCP Sockets Used : NO
Calling Number : 1818
Called Number : 0000211972595243897
Source IP Address (Sig ): 40.40.1.5
Destn SIP Req Addr:Port : 50.50.1.1:5075
Destn SIP Resp Addr:Port : 50.50.1.1:5075
Destination Name : 50.50.1.1

Aug 5 13:31:50.267: //7776/1DBED30688A3/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): 40.40.1.5
Source IP Port (Media): 17568
Destn IP Address (Media): 50.50.1.1
Destn IP Port (Media): 5077
Orig Destn IP Address:Port (Media): [ - ]:0

Aug 5 13:31:50.267: //7776/1DBED30688A3/SIP/Call/sipSPICallInfo:
Disconnect Cause (CC) : 21
Disconnect Cause (SIP) : 403

Aug 5 13:38:59.198: //-1/xxxxxxxxxxxx/SIP/Error/sipSPILocateInviteDialogCCB: Could not find ccb for response
Aug 5 13:38:59.198: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
Aug 5 13:38:59.198: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
Aug 5 13:38:59.198: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
Aug 5 13:38:59.198: //8006/2726943C8010/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 180 Ringing

Via: SIP/2.0/UDP 40.40.1.5:5060;branch=z9hG4bK24D7180E

From: <sip:8547845654@70.70.1.2>;tag=315EA40-D88

To: <sip:7248454145@abc.sip.com>;tag=10.0.1.10+1+9d416+c9e210eb

Call-ID: 272B76AD-3AAE11E5-88BCBB8F-D9E5C8FF@40.40.1.5

CSeq: 102 INVITE

Timestamp: 1438781937

Server: DC-SIP/2.0

Organization: MetaSwitch

Require: 100rel

Contact: <sip:7248454145@70.70.1.2:5060;transport=udp>

RSeq: 122756028

Content-Length: 0

Aug 5 13:38:59.198: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
Aug 5 13:38:59.198: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentSDP: No SDP found in inbound container
Aug 5 13:38:59.198: //8006/2726943C8010/SIP/Info/ccsip_api_call_alert: SDP Body either absent or ignored in 180 RINGING:- will wait for 200 OK to do negotiation.
Aug 5 13:38:59.198: //8006/2726943C8010/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
Aug 5 13:38:59.198: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
Aug 5 13:38:59.198: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
Aug 5 13:38:59.198: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message

Aug 5 13:38:59.198: //8006/2726943C8010/SIP/Info/HandleSIP1xxRinging: ccsip_api_call_alert returned: SIP_SUCCESS
Aug 5 13:38:59.198: //8006/2726943C8010/SIP/State/sipSPIChangeState: 0x4BA2E6A0 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) to (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING)
Aug 5 13:38:59.198: //8006/2726943C8010/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 2 event
Aug 5 13:38:59.198: //8006/2726943C8010/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
Aug 5 13:38:59.198: //8006/2726943C8010/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
Aug 5 13:38:59.198: //8006/2726943C8010/SIP/Info/sipSPIGenerateAuthorizationResponse: HA1 is: d9eb1e751b3fdbabb7a4cf0a7ce1880b
Aug 5 13:38:59.198: //8006/2726943C8010/SIP/Info/sipSPISendPrack: Associated container=0x4BEA1B88 to Prack
Aug 5 13:38:59.198: //8006/2726943C8010/SIP/Transport/sipSPISendPrack: Sending PRACK to the transport layer
Aug 5 13:38:59.202: //8006/2726943C8010/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
Aug 5 13:38:59.894: //8006/2726943C8010/SIP/Info/act_recdproc_new_message_response: Transaction Complete. Lock on Facilities released.
Aug 5 13:39:00.634: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [70.70.1.2]:5060, local_address:[ - ]
Aug 5 13:39:00.634: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
Aug 5 13:39:00.634: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
Aug 5 13:39:00.634: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
Aug 5 13:39:00.634: //8006/2726943C8010/SIP/Info/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK24DA3BF from via branch list
Aug 5 13:39:00.634: //8006/2726943C8010/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 40.40.1.5:5060;branch=z9hG4bK24DA3BF

From: <sip:8547845654@70.70.1.2>;tag=315EA40-D88

To: <sip:7248454145@abc.sip.com>;tag=10.0.1.10+1+9d416+c9e210eb

Call-ID: 272B76AD-3AAE11E5-88BCBB8F-D9E5C8FF@40.40.1.5

CSeq: 103 PRACK

Server: DC-SIP/2.0

Organization: MetaSwitch

Allow-Events: message-summary, refer, dialog, line-seize, presence, call-info, as-feature-event

Supported: resource-priority, 100rel

Content-Length: 0

Aug 5 13:39:00.634: //8006/2726943C8010/SIP/Info/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX
Aug 5 13:39:00.634: //8006/2726943C8010/SIP/Info/act_recdproc_new_message_response: Transaction Complete. Lock on Facilities released.
Aug 5 13:39:03.583: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x4B98B588) with key=[8004] to table
Aug 5 13:39:03.583: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
Aug 5 13:39:03.583: //-1/000000000000/SIP/Info/ccsip_iwf_init:
Aug 5 13:39:03.583: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:
Aug 5 13:39:03.583: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization: Entry...
Aug 5 13:39:03.583: //-1/000000000000/SIP/Info/ccsipRegisterSetTargetInfo: p2p mode with Registrar Server = dns:abc.sip.com
Aug 5 13:39:03.583: //-1/000000000000/SIP/Info/ccsipRegisterSetTargetInfo: Parsing The Registrar Address
Aug 5 13:39:03.583: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : abc.sip.com target_port : 5060

Aug 5 13:39:03.583: //-1/000000000000/SIP/Info/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host
Aug 5 13:39:03.583: //-1/000000000000/SIP/Info/sipSPIOutboundProxyReuse: Do not reuse Outbound Proxy IP adress and Port
Aug 5 13:39:03.583: //-1/000000000000/SIP/State/sipSPIChangeState: 0x4B98B588 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
Aug 5 13:39:03.583: //-1/000000000000/SIP/Info/ccsip_spi_registrar_add_expires_header: Inside ccsip_spi_registrar_add_expires_header for Expires
Aug 5 13:39:03.583: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_OUTBOUND_REGISTER
Aug 5 13:39:03.583: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIIncrementOverloadCount: Local 1 Global 2
Aug 5 13:39:03.583: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 40
Aug 5 13:39:03.583: //-1/000000000000/SIP/Info/act_idle_outgoing_register: In act_idle_outgoing_register

Aug 5 13:39:03.583: //8010/000000000000/SIP/Info/act_idle_outgoing_register: Send REGISTER to abc.sip.com:5060

Aug 5 13:39:03.583: //8010/000000000000/SIP/Info/sipSPIUaddCcbToUACTable: ****Adding to UAC table.
Aug 5 13:39:03.583: //8010/000000000000/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x4B98B588 key=AA598EEA-3A9311E5-8695BB8F-D9E5C8FF
Aug 5 13:39:03.583: //8010/000000000000/SIP/Info/act_idle_outgoing_register: Locally Resolved IP:70.70.1.2:5060
Aug 5 13:39:03.583: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
Aug 5 13:39:03.583: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
Aug 5 13:39:03.583: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 40.40.1.5
Aug 5 13:39:03.583: //8010/000000000000/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 7 event
Aug 5 13:39:03.583: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB
Aug 5 13:39:03.583: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB
Aug 5 13:39:03.583: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CDT to SIP default timezone = GMT
Aug 5 13:39:03.587: //8010/000000000000/SIP/Info/sipSPISendRegister: Associated container=0x4BEA3B80 to Register
Aug 5 13:39:03.587: //8010/000000000000/SIP/Transport/sipSPISendRegister: Sending REGISTER to the transport layer
Aug 5 13:39:03.587: //8010/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
Aug 5 13:39:03.587: //8010/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x49DCC8A0, addr=70.70.1.2, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x41C2EE94
Aug 5 13:39:03.587: //8010/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
Aug 5 13:39:03.587: //8010/000000000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
Aug 5 13:39:03.587: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:70.70.1.2, rport:5060 with laddr:

Aug 5 13:39:03.587: //8010/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x49DCC8A0
Aug 5 13:39:03.587: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x49DCC8A0, addr=70.70.1.2, port=5060, local_addr=, connId=2 for UDP
Aug 5 13:39:03.587: //8010/000000000000/SIP/State/sipSPIChangeState: 0x4B98B588 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE)
Aug 5 13:39:03.587: //8010/000000000000/SIP/State/sipSPIChangeState: 0x4B98B588 : State change from (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE)
Aug 5 13:39:03.587: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
REGISTER sip:abc.sip.com:5060 SIP/2.0

Via: SIP/2.0/UDP 40.40.1.5:5060;branch=z9hG4bK24DBD25

From: <sip:8547845657@abc.sip.com>;tag=31604C0-12EC

To: <sip:8547845657@abc.sip.com>

Date: Wed, 05 Aug 2015 13:39:03 GMT

Call-ID: AA598EEA-3A9311E5-8695BB8F-D9E5C8FF

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

Max-Forwards: 70

Timestamp: 1438781943

CSeq: 193 REGISTER

Contact: <sip:8547845657@40.40.1.5:5060>

Expires: 200

Supported: path

Content-Length: 0

Aug 5 13:39:04.251: //-1/xxxxxxxxxxxx/SIP/Error/get_content_length: Could not get Content-length
Aug 5 13:39:04.255: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [70.70.1.2]:5060, local_address:[ - ]
Aug 5 13:39:04.255: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CDT to SIP default timezone = GMT
Aug 5 13:39:04.255: //8010/000000000000/SIP/Info/sipSPISendRegister: Associated container=0x4BEA3B80 to Register
Aug 5 13:39:04.255: //8010/000000000000/SIP/Transport/sipSPISendRegister: Sending REGISTER to the transport layer
Aug 5 13:39:04.255: //8010/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
Aug 5 13:39:04.255: //8010/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x49DCC8A0, addr=70.70.1.2, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x0
Aug 5 13:39:04.255: //8010/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
Aug 5 13:39:04.255: //8010/000000000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
Aug 5 13:39:04.255: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:70.70.1.2, rport:5060 with laddr:

Aug 5 13:39:04.255: //8010/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x49DCC8A0
Aug 5 13:39:04.255: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x49DCC8A0, addr=70.70.1.2, port=5060, local_addr=, connId=2 for UDP
Aug 5 13:39:04.255: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
Aug 5 13:39:04.255: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
Aug 5 13:39:04.255: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
Aug 5 13:39:04.255: //8010/000000000000/SIP/Info/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK24DBD25 from via branch list
Aug 5 13:39:04.255: //8010/000000000000/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 40.40.1.5:5060;branch=z9hG4bK24DBD25

From: <sip:8547845657@70.70.1.2>;tag=31604C0-12EC

To: <sip:8547845657@abc.sip.com>;tag=aprqh0gj0l2-db5na8100002c

Call-ID: AA598EEA-3A9311E5-8695BB8F-D9E5C8FF

Timestamp: 1438781943

CSeq: 193 REGISTER

Contact: <sip:8547845657@40.40.1.5:5060>;expires=104

Aug 5 13:39:04.255: //8010/000000000000/SIP/Info/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX
Aug 5 13:39:04.255: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDecrementOverloadCount: Count:Local 0 Global 1
Aug 5 13:39:04.255: //8010/000000000000/SIP/Info/sipSPIRegPthruProcessResponse: Processing response w/ resp code == 200
Aug 5 13:39:04.255: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetRPCBFromRCB: Retreiving RCB [0x4BD3A5A4] from RPCB [0x0]
Aug 5 13:39:04.255: //8010/000000000000/SIP/Error/sipSPIRegPthruProcessResponse: Error NO RPCB

Aug 5 13:39:04.255: //-1/xxxxxxxxxxxx/SIP/Info/ccsipRegisterStartRCBTimer: Starting timer for pattern 8547845657 for 83 seconds
Aug 5 13:39:04.259: //8010/000000000000/SIP/Info/ccsip_gw_register_process_response: No P-Assoicated-URI present in Register Response
Aug 5 13:39:04.259: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[8004] removed.
Aug 5 13:39:04.259: //8010/000000000000/SIP/Info/sipSPIUdeleteCcbFromUACTable: ****Deleting from UAC table.
Aug 5 13:39:04.259: //8010/000000000000/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x4B98B588 key=AA598EEA-3A9311E5-8695BB8F-D9E5C8FF
Aug 5 13:39:04.259: //8010/000000000000/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
Aug 5 13:39:04.259: //8010/000000000000/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
Aug 5 13:39:04.259: //8010/000000000000/SIP/Info/ccsip_offer_ans_delete:
Aug 5 13:39:04.259: //8010/000000000000/SIP/Info/ccsip_iwf_delete:
Aug 5 13:39:04.259: //8010/000000000000/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 4B98B588
Aug 5 13:39:04.259: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[8004]
Aug 5 13:39:04.271: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
REGISTER sip:abc.sip.com:5060 SIP/2.0

Via: SIP/2.0/UDP 40.40.1.5:5060;branch=z9hG4bK24DBD25

From: <sip:8547845657@abc.sip.com>;tag=31604C0-12EC

To: <sip:8547845657@abc.sip.com>

Date: Wed, 05 Aug 2015 13:39:04 GMT

Call-ID: AA598EEA-3A9311E5-8695BB8F-D9E5C8FF

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

Max-Forwards: 70

Timestamp: 1438781944

CSeq: 193 REGISTER

Contact: <sip:8547845657@40.40.1.5:5060>

Expires: 200

Supported: path

Content-Length: 0

Aug 5 13:39:04.739: //-1/xxxxxxxxxxxx/SIP/Error/get_content_length: Could not get Content-length
Aug 5 13:39:04.739: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [70.70.1.2]:5060, local_address:[ - ]
Aug 5 13:39:04.739: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
Aug 5 13:39:04.739: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
Aug 5 13:39:04.739: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
Aug 5 13:39:04.739: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 40.40.1.5:5060;branch=z9hG4bK24DBD25

From: <sip:8547845657@70.70.1.2>;tag=31604C0-12EC

To: <sip:8547845657@abc.sip.com>;tag=aprqh0gj0l2-db5na8100002c

Call-ID: AA598EEA-3A9311E5-8695BB8F-D9E5C8FF

Timestamp: 1438781943

CSeq: 193 REGISTER

Contact: <sip:8547845657@40.40.1.5:5060>;expires=104

Aug 5 13:39:04.739: //-1/xxxxxxxxxxxx/SIP/Error/sipSPILocateInviteDialogCCB: Could not find ccb for response
Aug 5 13:39:06.143: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x4B98B588) with key=[8005] to table
Aug 5 13:39:06.143: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
Aug 5 13:39:06.143: //-1/000000000000/SIP/Info/ccsip_iwf_init:
Aug 5 13:39:06.143: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:
Aug 5 13:39:06.143: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization: Entry...
Aug 5 13:39:06.143: //-1/000000000000/SIP/Info/ccsipRegisterSetTargetInfo: p2p mode with Registrar Server = dns:abc.sip.com
Aug 5 13:39:06.143: //-1/000000000000/SIP/Info/ccsipRegisterSetTargetInfo: Parsing The Registrar Address
Aug 5 13:39:06.143: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : abc.sip.com target_port : 5060

Aug 5 13:39:06.143: //-1/000000000000/SIP/Info/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host
Aug 5 13:39:06.143: //-1/000000000000/SIP/Info/sipSPIOutboundProxyReuse: Do not reuse Outbound Proxy IP adress and Port
Aug 5 13:39:06.143: //-1/000000000000/SIP/State/sipSPIChangeState: 0x4B98B588 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
Aug 5 13:39:06.143: //-1/000000000000/SIP/Info/ccsip_spi_registrar_add_expires_header: Inside ccsip_spi_registrar_add_expires_header for Expires
Aug 5 13:39:06.143: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_OUTBOUND_REGISTER
Aug 5 13:39:06.143: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIIncrementOverloadCount: Local 1 Global 2
Aug 5 13:39:06.143: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 40
Aug 5 13:39:06.143: //-1/000000000000/SIP/Info/act_idle_outgoing_register: In act_idle_outgoing_register

Aug 5 13:39:06.143: //8011/000000000000/SIP/Info/act_idle_outgoing_register: Send REGISTER to abc.sip.com:5060

Aug 5 13:39:06.143: //8011/000000000000/SIP/Info/sipSPIUaddCcbToUACTable: ****Adding to UAC table.
Aug 5 13:39:06.143: //8011/000000000000/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x4B98B588 key=E522A889-3A9311E5-86A2BB8F-D9E5C8FF
Aug 5 13:39:06.143: //8011/000000000000/SIP/Info/act_idle_outgoing_register: Locally Resolved IP:70.70.1.2:5060
Aug 5 13:39:06.143: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
Aug 5 13:39:06.143: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
Aug 5 13:39:06.143: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 40.40.1.5
Aug 5 13:39:06.143: //8011/000000000000/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 7 event
Aug 5 13:39:06.143: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB
Aug 5 13:39:06.143: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB
Aug 5 13:39:06.143: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CDT to SIP default timezone = GMT
Aug 5 13:39:06.147: //8011/000000000000/SIP/Info/sipSPISendRegister: Associated container=0x4BEA75F0 to Register
Aug 5 13:39:06.147: //8011/000000000000/SIP/Transport/sipSPISendRegister: Sending REGISTER to the transport layer
Aug 5 13:39:06.147: //8011/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
Aug 5 13:39:06.147: //8011/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x49DCC8A0, addr=70.70.1.2, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x41C2EE94
Aug 5 13:39:06.147: //8011/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
Aug 5 13:39:06.147: //8011/000000000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
Aug 5 13:39:06.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:70.70.1.2, rport:5060 with laddr:

Aug 5 13:39:06.147: //8011/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x49DCC8A0
Aug 5 13:39:06.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x49DCC8A0, addr=70.70.1.2, port=5060, local_addr=, connId=2 for UDP
Aug 5 13:39:06.147: //8011/000000000000/SIP/State/sipSPIChangeState: 0x4B98B588 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE)
Aug 5 13:39:06.147: //8011/000000000000/SIP/State/sipSPIChangeState: 0x4B98B588 : State change from (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE)
Aug 5 13:39:06.147: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Sent:
REGISTER sip:abc.sip.com:5060 SIP/2.0

Via: SIP/2.0/UDP 40.40.1.5:5060;branch=z9hG4bK24DC16E1

From: <sip:8547845658@abc.sip.com>;tag=3160EC0-220

To: <sip:8547845658@abc.sip.com>

Date: Wed, 05 Aug 2015 13:39:06 GMT

Call-ID: E522A889-3A9311E5-86A2BB8F-D9E5C8FF

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

Max-Forwards: 70

Timestamp: 1438781946

CSeq: 191 REGISTER

Contact: <sip:8547845658@40.40.1.5:5060>

Expires: 200

Supported: path

Content-Length: 0

Aug 5 13:39:06.923: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [70.70.1.2]:5060, local_address:[ - ]
Aug 5 13:39:06.927: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CDT to SIP default timezone = GMT
Aug 5 13:39:06.927: //8011/000000000000/SIP/Info/sipSPISendRegister: Associated container=0x4BEA75F0 to Register
Aug 5 13:39:06.927: //8011/000000000000/SIP/Transport/sipSPISendRegister: Sending REGISTER to the transport layer
Aug 5 13:39:06.927: //8011/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
Aug 5 13:39:06.927: //8011/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x49DCC8A0, addr=70.70.1.2, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x0
Aug 5 13:39:06.927: //8011/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
Aug 5 13:39:06.927: //8011/000000000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
Aug 5 13:39:06.927: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:70.70.1.2, rport:5060 with laddr:

Aug 5 13:39:06.927: //8011/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x49DCC8A0
Aug 5 13:39:06.927: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x49DCC8A0, addr=70.70.1.2, port=5060, local_addr=, connId=2 for UDP
Aug 5 13:39:06.927: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
Aug 5 13:39:06.927: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
Aug 5 13:39:06.927: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
Aug 5 13:39:06.927: //8011/000000000000/SIP/Info/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK24DC16E1 from via branch list
Aug 5 13:39:06.927: //8011/000000000000/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 401 Unauthorized

Via: SIP/2.0/UDP 40.40.1.5:5060;branch=z9hG4bK24DC16E1

From: <sip:8547845658@70.70.1.2>;tag=3160EC0-220

To: <sip:8547845658@abc.sip.com>;tag=10.0.1.10+1+a2105+886a4000

Call-ID: E522A889-3A9311E5-86A2BB8F-D9E5C8FF

Timestamp: 1438781946

CSeq: 191 REGISTER

WWW-Authenticate: Digest realm="abc.sip.com",nonce="5b0025d8e94b",stale=false,algorithm=MD5,qop="auth"

Server: DC-SIP/2.0

Organization: MetaSwitch

Content-Length: 0

Aug 5 13:39:06.927: //8011/000000000000/SIP/Info/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX
Aug 5 13:39:06.927: //8011/000000000000/SIP/Info/sipSPIGenerateAuthorizationResponse: HA1 is: d9eb1e751b3fdbabb7a4cf0a7ce1880b
Aug 5 13:39:06.927: //8011/000000000000/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 7 event
Aug 5 13:39:06.927: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB
Aug 5 13:39:06.931: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB
Aug 5 13:39:06.931: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CDT to SIP default timezone = GMT
Aug 5 13:39:06.931: //8011/000000000000/SIP/Info/sipSPISendRegister: Associated container=0x4BEA7178 to Register
Aug 5 13:39:06.931: //8011/000000000000/SIP/Transport/sipSPISendRegister: Sending REGISTER to the transport layer
Aug 5 13:39:06.931: //8011/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
Aug 5 13:39:06.931: //8011/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x4B4AAC0C, addr=70.70.1.2, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x41C2EE94
Aug 5 13:39:06.931: //8011/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
Aug 5 13:39:06.931: //8011/000000000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
Aug 5 13:39:06.931: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:70.70.1.2, rport:5060 with laddr:

Aug 5 13:39:06.931: //8011/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x4B4AAC0C
Aug 5 13:39:06.931: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x4B4AAC0C, addr=70.70.1.2, port=5060, local_addr=, connId=2 for UDP
Aug 5 13:39:06.931: //8011/000000000000/SIP/State/sipSPIChangeState: 0x4B98B588 : State change from (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE)
Aug 5 13:39:06.943: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x4BA28CA8) with key=[8006] to table
Aug 5 13:39:06.943: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
Aug 5 13:39:06.947: //-1/000000000000/SIP/Info/ccsip_iwf_init:
Aug 5 13:39:06.947: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:
Aug 5 13:39:06.947: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization: Entry...
Aug 5 13:39:06.947: //-1/000000000000/SIP/Info/ccsipRegisterSetTargetInfo: p2p mode with Registrar Server = dns:abc.sip.com
Aug 5 13:39:06.947: //-1/000000000000/SIP/Info/ccsipRegisterSetTargetInfo: Parsing The Registrar Address
Aug 5 13:39:06.947: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : abc.sip.com target_port : 5060

Aug 5 13:39:06.947: //-1/000000000000/SIP/Info/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host
Aug 5 13:39:06.947: //-1/000000000000/SIP/Info/sipSPIOutboundProxyReuse: Do not reuse Outbound Proxy IP adress and Port
Aug 5 13:39:06.947: //-1/000000000000/SIP/State/sipSPIChangeState: 0x4BA28CA8 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
Aug 5 13:39:06.947: //-1/000000000000/SIP/Info/ccsip_spi_registrar_add_expires_header: Inside ccsip_spi_registrar_add_expires_header for Expires
Aug 5 13:39:06.947: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_OUTBOUND_REGISTER
Aug 5 13:39:06.947: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIIncrementOverloadCount: Local 1 Global 3
Aug 5 13:39:06.947: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 40
Aug 5 13:39:06.947: //-1/000000000000/SIP/Info/act_idle_outgoing_register: In act_idle_outgoing_register

Aug 5 13:39:06.947: //8012/000000000000/SIP/Info/act_idle_outgoing_register: Send REGISTER to abc.sip.com:5060

Aug 5 13:39:06.947: //8012/000000000000/SIP/Info/sipSPIUaddCcbToUACTable: ****Adding to UAC table.
Aug 5 13:39:06.947: //8012/000000000000/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x4BA28CA8 key=1789B3BD-3A9411E5-86B1BB8F-D9E5C8FF
Aug 5 13:39:06.947: //8012/000000000000/SIP/Info/act_idle_outgoing_register: Locally Resolved IP:70.70.1.2:5060
Aug 5 13:39:06.947: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
Aug 5 13:39:06.947: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
Aug 5 13:39:06.947: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 40.40.1.5
Aug 5 13:39:06.947: //8012/000000000000/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 7 event
Aug 5 13:39:06.947: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB
Aug 5 13:39:06.947: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB
Aug 5 13:39:06.947: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CDT to SIP default timezone = GMT
Aug 5 13:39:06.947: //8012/000000000000/SIP/Info/sipSPISendRegister: Associated container=0x4BEA7388 to Register
Aug 5 13:39:06.947: //8012/000000000000/SIP/Transport/sipSPISendRegister: Sending REGISTER to the transport layer
Aug 5 13:39:06.947: //8012/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
Aug 5 13:39:06.947: //8012/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x4B4C7800, addr=70.70.1.2, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x41C2EE94
Aug 5 13:39:06.947: //8012/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
Aug 5 13:39:06.951: //8012/000000000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
Aug 5 13:39:06.951: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:70.70.1.2, rport:5060 with laddr:

Aug 5 13:39:06.951: //8012/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x4B4C7800
Aug 5 13:39:06.951: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x4B4C7800, addr=70.70.1.2, port=5060, local_addr=, connId=2 for UDP
Aug 5 13:39:06.951: //8012/000000000000/SIP/State/sipSPIChangeState: 0x4BA28CA8 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE)
Aug 5 13:39:06.951: //8012/000000000000/SIP/State/sipSPIChangeState: 0x4BA28CA8 : State change from (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE)
Aug 5 13:39:06.951: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
REGISTER sip:abc.sip.com:5060 SIP/2.0

Via: SIP/2.0/UDP 40.40.1.5:5060;branch=z9hG4bK24DC16E1

From: <sip:8547845658@abc.sip.com>;tag=3160EC0-220

To: <sip:8547845658@abc.sip.com>

Date: Wed, 05 Aug 2015 13:39:06 GMT

Call-ID: E522A889-3A9311E5-86A2BB8F-D9E5C8FF

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

Max-Forwards: 70

Timestamp: 1438781946

CSeq: 191 REGISTER

Contact: <sip:8547845658@40.40.1.5:5060>

Expires: 200

Supported: path

Content-Length: 0

Aug 5 13:39:06.951: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
REGISTER sip:abc.sip.com:5060 SIP/2.0

Via: SIP/2.0/UDP 40.40.1.5:5060;branch=z9hG4bK24DD841

From: <sip:8547845658@abc.sip.com>;tag=3160EC0-220

To: <sip:8547845658@abc.sip.com>

Date: Wed, 05 Aug 2015 13:39:06 GMT

Call-ID: E522A889-3A9311E5-86A2BB8F-D9E5C8FF

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

Max-Forwards: 70

Timestamp: 1438781946

CSeq: 192 REGISTER

Contact: <sip:8547845658@40.40.1.5:5060>

Expires: 200

Authorization: Digest username="8547845654",realm="abc.sip.com",uri="sip:abc.sip.com:5060",response="f63b5925fa5232f8f147d80ed03d6a08",nonce="5b0025d8e94b",cnonce="D609F763",qop=auth,algorithm=MD5,nc=00000001

Content-Length: 0

Regards,

MUKESH KUMAR | Network Engineer

Spooster IT Services

Computer Networking Solutions

mjindal@spooster.com

www.spooster.com

Vivek Batra · ‎08-25-2015

Can you please disable all debugs except debug ccsip messages... seems couple of SIP messages are missing.

Ayodeji Okanlawon · ‎09-03-2013

Hi,

I have looked at the traces and the problem is from your CUBE. Here is my analysis

1. When ITSP sent the first 180 ringing with SDP, it indicated that it wanted to do early media and requested a PRACK.

"Require: 100rel"

Received:

SIP/2.0 180 Ringing

Via: SIP/2.0/UDP 21.10.0.3:5060;branch=z9hG4bKBA319D8

From: "ATA187 Core" <6001>;tag=3E21E5CC-34E

To: <40042484>;tag=277bus7u-CC-42

Call-ID: AAE9B01E-134F11E3-B2E7A8D4-D9EFC3D@21.10.0.3

CSeq: 101 INVITE

Timestamp: 1378158264

Contact: <40042484>

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

Require: 100rel

RSeq: 1

Content-Length: 228

Content-Type: application/sdp

v=0

o=HuaweiSoftX3000 12465003 12465003 IN IP4 10.57.0.117

s=Sip Call

c=IN IP4 10.57.0.117

t=0 0

m=audio 19728 RTP/AVP 18 101

a=rtpmap:18 G729/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=fmtp:18 annexb=no

2. However when CUBE sent a PRACK to the ITSP it included no answer to their offer, ie no SDP.

Sent:

PRACK sip:40042484@10.56.14.18:5060;user=phone;transport=udp SIP/2.0

Via: SIP/2.0/UDP 21.10.0.3:5060;branch=z9hG4bKBA4169E

From: "ATA187 Core" <6001>;tag=3E21E5CC-34E

To: <40042484>;tag=277bus7u-CC-42

Date: Mon, 02 Sep 2013 21:44:24 GMT

Call-ID: AAE9B01E-134F11E3-B2E7A8D4-D9EFC3D@21.10.0.3

CSeq: 102 PRACK

RAck: 1 101 INVITE

Allow-Events: telephone-event

Max-Forwards: 70

Content-Length: 0

As you can see there is no SDP in the PRACK sent to the ITSP. This is where everything broke. The next few lines, ITSP then sent another 180 ringing without SDP and still requested PRACK, perhaps hoping that CUBE will send offers in its PRACK, but CUBE still ddint send anything...

PRACK is used to establish early media or to cut through audio on the PROGRESS message or ringing in this case. Hence there is no way this can be achieved if CUBE doesnt send SDP in its PRACK message in this scenario.

So we need to find out why CUBE is behaving this way. Please attach a sh run of your gateway.

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

Please rate all useful posts

jfernandorosa · ‎09-03-2013

Hi,

Attached config the cube.

Thanks for help!

Joao

jfernandorosa · ‎09-03-2013

Hi,

I remove in sip-ua:

disable-early-media 180

The calls in work fine!

Thanks for help!

Regards.

Joao

jfernandorosa · ‎09-03-2013

Hi Aokanlawon,

Thanks for help! Five stars for you.

Regards.

Joao

jfernandorosa · ‎09-03-2013

Hi,

After this change, my fax services don´t work, I call to number receive a ring, receive a signal and return a fast busy.

I attached logs.

Joao

Ayodeji Okanlawon · ‎09-03-2013

I can see that the call starts as g729 and changed to G711 when a fax tone was detected at the far end..

What is the ip address of the device your fax is connected to? What is the region setting between your fax device and the gateway?

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

Please rate all useful posts

jfernandorosa · ‎09-03-2013

IP Endpoint ATA187 is: 21.10.1.50

Region between Fax and Gateway is G711

.

Thanks!

Joao

Ayodeji Okanlawon · ‎09-03-2013

You need to reconfigure the dial-peers for your fax devices. The voice call setup is sent to a xcoder..

From the logs, RTP stream is sent to ip address 21.10.0.2.

Received:

ACK sip:297832422526@21.10.0.3:5060;transport=tcp SIP/2.0

Via: SIP/2.0/TCP 21.10.0.7:5060;branch=z9hG4bK153f6bc5cebe

From: "ATA187 Core" <6001>;tag=24382~fb89236f-816b-47f5-8c94-b8d3c388dd7c-64665213

To: <297832422526>;tag=4272C5B4-D17

Date: Tue, 03 Sep 2013 17:53:30 GMT

Call-ID: bcc58e80-2261221a-c15-7000a15@21.10.0.7

Max-Forwards: 70

CSeq: 101 ACK

Allow-Events: presence, kpml

Content-Type: application/sdp

Content-Length: 251

v=0

o=CiscoSystemsCCM-SIP 24382 1 IN IP4 21.10.0.7

s=SIP Call

c=IN IP4 21.10.0.2

That suggest that the call is routed to a transcoder or MTP device...can you confirm what device is this.

If the region between your ATA and CUBE is G711, then you need to have the inbound dial-peer from CUCM advertise G711 and your outbound dial-peer to your ITSP using G711 for fax calls only, all other calls can use G729

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepare

Please rate all useful posts

jfernandorosa · ‎09-03-2013

Hi,

21.10.0.2 is a CUBE with MTP and transcoder.

I forced call to use G711 in dial-peer (in and out), but not successfully, attached logs with G711.

Thanks.

Joao

Ayodeji Okanlawon · ‎09-03-2013

I can see the call using G711 however rtp is still sent to c=IN IP4 21.10.0.6.

For your fax to work media/rtp stream has to be sent directly to the ATA.

Looking at your config, I can see that this device is a MTP device. So there is a DTMF mistmact hence calls are terminated on the MTP..

Try and add this to your inbound voip dial-peer

dial-peer voice 2 voip

description # Call Leg VOIP #

incoming called-number .

dtmf-relay rtp-nte digit-drop sip-kpml

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

Please rate all useful posts

jfernandorosa · ‎09-03-2013

21.10.0.6 is a CUCM.

I can´t insert the RTP comands, in inbound dial-peer is not exist:

ra076963.igs.cref(config-dial-peer)#dtmf-relay rtp-nte digit-drop ?

cisco-rtp Cisco Proprietary RTP

h245-alphanumeric DTMF Relay via H245 Alphanumeric IE

h245-signal DTMF Relay via H245 Signal IE

I insert:

dial-peer voice 2 voip

description # Call Leg VOIP #

incoming called-number .

dtmf-relay rtp-nte digit-drop

Not working.

Thanks!

Joao

Ayodeji Okanlawon · ‎09-03-2013

Dont you have a sip trunk between CUCM and CUBE? If you do then your dial-peer 2 should have session protocol sipv2 on it. You need the dial-peer to be enabled for sip to add that command

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

Please rate all useful posts