SIP Trunk unable to make outbound calls

[lukedp]

I am having trouble configuring a SIP trunk, i am able to make call into the cube and call manager, however when it comes to make out bound calls the calls appear to drop off and fail to resume. I have been looking around and have been unable to see any issues. currently i am testing the sip connection on the secondary back up cube that is 10.70.13.10. the primary cucm is 10.60.3.20 and the subscriber is 10.70.13.20.

I am currently using Call Manager 9.0 for CUCM

I am using using a 2921 with version 15.1(4)M4 for the Cube.

in the example i am trying to call the 0444888333 number from an internal phone.

on the sip trunk i have set the displayed number as 625058000

INVITE sip:0444888333@10.70.13.10:5060 SIP/2.0

Via: SIP/2.0/UDP 10.60.3.20:5060;branch=z9hG4bK4f173d46d8

Remote-Party-ID: "The Client" <sip:10.60.3.20>;party=calling;screen=yes;privacy=off

From: "The Client" <sip:62505800@10.60.3.20>;tag=129~a928f5a0-237e-4cbd-9716-954b915b4a58-24190856

To: <sip:0444888333@10.70.13.10>

Date: Mon, 25 Feb 2013 04:21:42 GMT

Call-ID: da0e1480-12a1e6d6-4d-14033c0a@10.60.3.20

Supported: timer,resource-priority,replaces

Min-SE:  1800

User-Agent: Cisco-CUCM9.0

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

CSeq: 101 INVITE

Expires: 180

Allow-Events: presence

Supported: X-cisco-srtp-fallback,X-cisco-original-called

Cisco-Guid: 3658355840-0000065536-0000000065-0335756298

Session-Expires:  1800

Contact: <sip:62505800@10.60.3.20:5060>;video;audio

Max-Forwards: 70

Content-Length: 0

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x2AE096C0) with key=[4433] to table

Feb 25 04:21:42.139: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:

Feb 25 04:21:42.139: //-1/000000000000/SIP/Info/ccsip_iwf_init:

Feb 25 04:21:42.139: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:

Feb 25 04:21:42.139: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.60.3.20,Port 5060, Transport 1, SentBy Port 5060

Feb 25 04:21:42.139: //-1/000000000000/SIP/Info/resolve_sig_ip_address_to_bind: signaling bind address : 10.70.13.10

Feb 25 04:21:42.139: //-1/DA0E14800000/SIP/State/sipSPIChangeState: 0x2AE096C0 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.60.3.20,Port 5060, Transport 1, SentBy Port 5060

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone AWST to SIP default timezone = GMT

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.60.3.20,Port 5060, Transport 1, SentBy Port 5060

Feb 25 04:21:42.139: //-1/DA0E14800000/SIP/Info/resolve_sig_ip_address_to_bind: signaling bind address : 10.70.13.10

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:

   Calling Number=0444888333, Called Number=0444888333, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:

   Match Rule=DP_MATCH_DEST; Called Number=0444888333

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=0444888333, Expanded String=0444888333, Calling Number=0444888333T

   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:

   Result=Success(0); Outgoing Dial-peer=33 Is Matched

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:

   Result=Success(0) after DP_MATCH_DEST

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:

   dialstring=0444888333, saf_enabled=1, saf_dndb_lookup=1, dp_result=0

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:

   Result=SUCCESS(0)

   List of Matched Outgoing Dial-peer(s):

     1: Dial-peer Tag=33

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckIpip: VOIP dialpeer (peer=0x29A73BC4) found for sip_user: 0444888333

Feb 25 04:21:42.139: //-1/DA0E14800000/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done

Feb 25 04:21:42.139: //-1/DA0E14800000/SIP/Info/sipSPISetInfoFromRpid: Received current remote name: The Client, current remote number:

Feb 25 04:21:42.139: //-1/DA0E14800000/SIP/Info/sipSPISetInfoFromRpid: Received ;screen=yes ;privacy=off -> Setting Octet3A 0x81, extended_privacy 0x00

Feb 25 04:21:42.139: //-1/DA0E14800000/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCSTA: No CSTA found in inbound container

Feb 25 04:21:42.139: //-1/DA0E14800000/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.

Feb 25 04:21:42.139: //-1/DA0E14800000/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x2AE096C0 key=da0e1480-12a1e6d6-4d-14033c0a@10.60.3.200444888333

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Calling Number=62505800, Called Number=, Voice-Interface=0x0,

   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,

   Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.139: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_ANSWER; Calling Number=62505800

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=62505800T

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Result=-1

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_ORIGINATE; Calling Number=62505800

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=62505800T

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:

   Result=Success(0); Incoming Dial-peer=33 Is Matched

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=33

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:

   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeer:exit@6613

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 0444888333

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 62505800

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name The Client, number 62505800, Calling oct3 0x00, oct_3a 0x81, Called number 0444888333

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:10.60.3.20:5060, Host:10.60.3.20

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 62505800

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Calling Number=62505800, Called Number=, Voice-Interface=0x0,

   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,

   Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_ANSWER; Calling Number=62505800

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=62505800T

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Result=-1

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_ORIGINATE; Calling Number=62505800

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=62505800T

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:

   Result=Success(0); Incoming Dial-peer=33 Is Matched

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=33

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:

   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeer:exit@6613

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpAssociateIncomingPeerCore:

   Calling Number=62505800, Called Number=0444888333, Voice-Interface=0x0,

   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,

   Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_VIA_URI; URI=sip:10.60.3.20:5060

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchCore:

   Result=-1

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchPeertype:exit@5985

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_REQUEST_URI; URI=sip:0444888333@10.70.13.10:5060

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchCore:

   Result=-1

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchPeertype:exit@5985

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_TO_URI; URI=sip:0444888333@10.70.13.10

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchCore:

   Result=-1

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchPeertype:exit@5985

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_FROM_URI; URI=sip:62505800@10.60.3.20

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchCore:

   Result=-1

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchPeertype:exit@5985

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_INCOMING_DNIS; Called Number=0444888333

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchCore:

   Dial String=0444888333, Expanded String=0444888333, Calling Number=

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/MatchNextPeer:

   Result=Success(0); Incoming Dial-peer=65 Is Matched

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchPeertype:exit@5985

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpAssociateIncomingPeerCore:

   Result=Success(0) after DP_MATCH_INCOMING_DNIS; Incoming Dial-peer=65

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpMatchSafModulePlugin:

   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0

Feb 25 04:21:42.143: //-1/DA0E14800000/DPM/dpAssociateIncomingPeerSPI:exit@6564

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIGetCallConfig: Peer tag 65 matched for incoming call

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/resolve_sig_ip_address_to_bind: signaling bind address : 10.70.13.10

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-AROUND

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_AROUND

Feb 25 04:21:42.143: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetSipProfilesTag: voice class SIP Profiles tag is set : 100

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 10 and offer-all is = FALSE

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIGetCallConfig: Media forking disabled

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIContinueNewMsgInvite: Calling name The Client, number 62505800, Calling oct3 0x00, oct_3a 0x81, ext_priv 0x00, Called number 0444888333, oct3 0x00

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIValidateRequestUri: Not Enabled

Feb 25 04:21:42.143: //-1/DA0E14800000/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0

Feb 25 04:21:42.143: //4429/DA0E14800000/SIP/Info/sipSPI_ipip_IsSDPPassthruEnabled:  - 0

Feb 25 04:21:42.143: //4429/DA0E14800000/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ

Feb 25 04:21:42.143: //4429/DA0E14800000/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:0, container:2BB80514

Feb 25 04:21:42.143: //4429/DA0E14800000/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr:

Session-Expires value: 1800 refresher: none

Feb 25 04:21:42.143: //4429/DA0E14800000/SIP/Info/Session-Timer/sipSTSLExtractMinSEHdr: Min-SE Duration: 1800

Feb 25 04:21:42.143: //4429/DA0E14800000/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ

Feb 25 04:21:42.143: //4429/DA0E14800000/SIP/Info/Session-Timer/sipSTSLInitialSRReqPeerEventGen: sending received session expires to the peer leg

Feb 25 04:21:42.143: //4429/DA0E14800000/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_PASS_ST_PARAMS, SE Value:1800, SE Refresher:none, Min-SE Value:1800, flags:2001

Feb 25 04:21:42.143: //4429/DA0E14800000/SIP/Info/Session-Timer/sipSTSLMain:

SE: 1800;refresher:none peer refresher:none, flags:2001, posted event:E_STSL_INVALID_PEER_EVENT, reason:4

Configured SE:1800, Configured Min-SE:1800

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found

Feb 25 04:21:42.147: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentSDP: No SDP found in inbound container

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPIDoQoSNegotiationWithNoMediaLine: Local Precondition: 1, Remote Precondition: 1

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPIDoQoSNegotiationWithNoMediaLine: MEDIA FLOW-AROUND CALL

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sip_iwf_def_copy_sdp_to_channelInfo:

CallID 4429, sdp 0x31693660 channels 0x2AE0AD14

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Delayed media case...creating new stream

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.70.13.10

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPI_ipip_set_flw_around_media: IP-IP flow-around mode configured: replace media addr with peer's

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Media/sipSPI_ipip_set_flw_around_media: Flow-around media src addr for stream 1:  src_addr = 10.70.13.10 : port = 0

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Media/sipSPIAddSDPMediaPayload: Preferred method of dtmf relay is: 6, with payload: 101

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = da0e1480-12a1e6d6-4d-14033c0a@10.60.3.20

Feb 25 04:21:42.147: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Unsupported header passthru is not configured and no headers are present in hdr_hash_queue

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled:  - 0

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Not Enabled

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/ccsip_api_call_setup_ind: Unable to add unsupp headers to container

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/ccsip_api_call_setup_ind: Set Protocol information

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 24

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPI_ipip_store_channel_info: negotiated dtmf not available, using dialpeer config dtmf = 6

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Media/sipSPIDisplayStreamInfo:

  Stream type            : voice+dtmf

  Media line             : 1

  State                  : STREAM_IDLE (1)

  Stream address type    : 1

  Callid                 : -1

  Peer Callid            : -1

  RTP/SRTP Negotiated     : 0

  Negotiated Codec       : No Codec   , bytes

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

  Negotiated DTMF relay  : inband-voice

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

  Negotiated CN payload  : 0

  Media Srce Addr/Port   : [10.70.13.10]:0

  Media Dest Addr/Port   : [ - ]:0

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPI_ipip_calculate_channel_count: Number of streams to report = 0

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPI_ipip_store_channel_info: Setting CHANNEL_COUNT = 0 for callid 4429

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPIShrlCall: Check peer: 65 for Shared-Line call, callid: 4429

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/ccsip_set_bearer_capability:

   Bearer Capability: Speech (0x00)

Feb 25 04:21:42.147: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container

Feb 25 04:21:42.147: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container

Feb 25 04:21:42.147: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS_DELAYED_MEDIA

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 114D to table

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPIUpdateCallEntry:

Call 4429 set InfoType to SPEECH

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:100, container:2BB81644

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/Session-Timer/sipSTSLValidateSessRefreshMsg: Ignoring 1xx response for session timer processing

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPISendInviteResponse: Associated container=0x2BB81644 to Invite Response 100

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Transport/sipSPITransportSendMessage: msg=0x313C83B0, addr=10.60.3.20, port=5060, sentBy_port=5060, local_addr=10.70.13.10, is_req=0, transport=1, switch=0, callBack=0x0

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0

Feb 25 04:21:42.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportLogicSendMsg: connection-reuse configured, listen conn-id : 2

Feb 25 04:21:42.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x313C83B0, addr=10.60.3.20, port=5060, local_addr=10.70.13.10, connId=2 for UDP

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/State/sipSPIChangeState: 0x2AE096C0 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (STATE_RECD_INVITE, SUBSTATE_NONE)

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Info/sipSPIProcessContactInfo: Previous Hop 10.60.3.20:5060

Feb 25 04:21:42.147: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:

   Calling Number=, Called Number=0444888333, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.147: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:

   Match Rule=DP_MATCH_DEST; Called Number=0444888333

Feb 25 04:21:42.147: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=0444888333, Expanded String=0444888333, Calling Number=

   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.147: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:

   Result=Success(0); Outgoing Dial-peer=33 Is Matched

Feb 25 04:21:42.147: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:

   Result=Success(0) after DP_MATCH_DEST

Feb 25 04:21:42.147: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:

   dialstring=0444888333, saf_enabled=0, saf_dndb_lookup=1, dp_result=0

Feb 25 04:21:42.147: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:

   Result=SUCCESS(0)

   List of Matched Outgoing Dial-peer(s):

     1: Dial-peer Tag=33

Feb 25 04:21:42.147: //4429/DA0E14800000/SIP/Msg/ccsipDisplayMsg:

Sent:

SIP/2.0 100 Trying

Via: SIP/2.0/UDP 10.60.3.20:5060;branch=z9hG4bK4f173d46d8

From: "The Client" <sip:62505800@10.60.3.20>;tag=129~a928f5a0-237e-4cbd-9716-954b915b4a58-24190856

To: <sip:0444888333@10.70.13.10>

Date: Mon, 25 Feb 2013 04:21:42 GMT

Call-ID: da0e1480-12a1e6d6-4d-14033c0a@10.60.3.20

CSeq: 101 INVITE

Allow-Events: telephone-event

Server: Cisco-SIPGateway/IOS-12.x

Content-Length: 0

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDING

Feb 25 04:21:42.151: //-1/DA0E14800000/DPM/dpMatchPeersCore:

   Calling Number=, Called Number=0444888333, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.151: //-1/DA0E14800000/DPM/dpMatchPeersCore:

   Match Rule=DP_MATCH_DEST; Called Number=0444888333

Feb 25 04:21:42.151: //-1/DA0E14800000/DPM/dpMatchCore:

   Dial String=0444888333, Expanded String=0444888333, Calling Number=

   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.151: //-1/DA0E14800000/DPM/MatchNextPeer:

   Result=Success(0); Outgoing Dial-peer=33 Is Matched

Feb 25 04:21:42.151: //-1/DA0E14800000/DPM/dpMatchPeersCore:

   Result=Success(0) after DP_MATCH_DEST

Feb 25 04:21:42.151: //-1/DA0E14800000/DPM/dpMatchSafModulePlugin:

   dialstring=0444888333, saf_enabled=0, saf_dndb_lookup=1, dp_result=0

Feb 25 04:21:42.151: //-1/DA0E14800000/DPM/dpMatchPeersMoreArg:

   Result=SUCCESS(0)

   List of Matched Outgoing Dial-peer(s):

     1: Dial-peer Tag=33

Feb 25 04:21:42.151: //-1/DA0E14800000/DPM/dpMatchPeersCore:

   Calling Number=, Called Number=0444888333, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.151: //-1/DA0E14800000/DPM/dpMatchPeersCore:

   Match Rule=DP_MATCH_DEST; Called Number=0444888333

Feb 25 04:21:42.151: //-1/DA0E14800000/DPM/dpMatchCore:

   Dial String=0444888333, Expanded String=0444888333, Calling Number=

   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.151: //-1/DA0E14800000/DPM/MatchNextPeer:

   Result=Success(0); Outgoing Dial-peer=33 Is Matched

Feb 25 04:21:42.151: //-1/DA0E14800000/DPM/dpMatchPeersCore:

   Result=Success(0) after DP_MATCH_DEST

Feb 25 04:21:42.151: //-1/DA0E14800000/DPM/dpMatchSafModulePlugin:

   dialstring=0444888333, saf_enabled=0, saf_dndb_lookup=1, dp_result=0

Feb 25 04:21:42.151: //-1/DA0E14800000/DPM/dpMatchPeersMoreArg:

   Result=SUCCESS(0)

   List of Matched Outgoing Dial-peer(s):

     1: Dial-peer Tag=33

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:

   Calling Number=0444888333, Called Number=0444888333, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:

   Match Rule=DP_MATCH_DEST; Called Number=0444888333

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=0444888333, Expanded String=0444888333, Calling Number=0444888333T

   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:

   Result=Success(0); Outgoing Dial-peer=33 Is Matched

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:

   Result=Success(0) after DP_MATCH_DEST

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:

   dialstring=0444888333, saf_enabled=0, saf_dndb_lookup=1, dp_result=0

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:

   Result=SUCCESS(0)

   List of Matched Outgoing Dial-peer(s):

     1: Dial-peer Tag=33

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Calling Number=0444888333, Called Number=, Voice-Interface=0x0,

   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,

   Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_ANSWER; Calling Number=0444888333

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=0444888333T

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Result=-1

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_ORIGINATE; Calling Number=0444888333

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=0444888333T

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:

   Result=Success(0); Incoming Dial-peer=33 Is Matched

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=33

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:

   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeer:exit@6613

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Calling Number=0444888333, Called Number=, Voice-Interface=0x0,

   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,

   Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_ANSWER; Calling Number=0444888333

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=0444888333T

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Result=-1

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Match Rule=DP_MATCH_ORIGINATE; Calling Number=0444888333

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:

   Is Incoming=TRUE, Number Expansion=FALSE

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:

   Dial String=, Expanded String=, Calling Number=0444888333T

   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:

   Result=Success(0); Incoming Dial-peer=33 Is Matched

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:

   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=33

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:

   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeer:exit@6613

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:

   Calling Number=, Called Number=0444888333, Peer Info Type=DIALPEER_INFO_SPEECH

Feb 25 04:21:42.151: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:

   Match Rule=DP_MATCH_DEST; Called Number=04448883335840-0000065536-0000000065-0335756298

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

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

CSeq: 101 INVITE

Timestamp: 1361766102

Contact: <sip:62505800@10.70.13.10:5060>

Expires: 300

Allow-Events: telephone-event

Max-Forwards: 69

Session-Expires:  1800

Content-Length: 0

Feb 25 04:21:42.731: //-1/xxxxxxxxxxxx/SIP/Error/get_content_length: Could not get Content-length

Feb 25 04:21:42.731: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [203.52.2.164]:5060, local_address:[10.70.13.10]

Feb 25 04:21:42.731: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone AWST to SIP default timezone = GMT

Feb 25 04:21:42.731: //4430/DA0E14800000/SIP/Event/sipSPICreateRpid: Received Octet3A=0x81 -> Setting ;screen=yes ;privacy=off

Feb 25 04:21:42.731: //4430/DA0E14800000/SIP/Info/sipSPISendInvite: Associated container=0x2BB810C4 to Invite

Feb 25 04:21:42.731: //4430/DA0E14800000/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer

Feb 25 04:21:42.731: //4430/DA0E14800000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE

Feb 25 04:21:42.731: //4430/DA0E14800000/SIP/Transport/sipSPITransportSendMessage: msg=0x313C83B0, addr=203.52.2.164, port=5060, sentBy_port=0, local_addr=10.70.13.10, is_req=1, transport=1, switch=0, callBack=0x0

Feb 25 04:21:42.731: //-1/xxxxxxxxxxxx/SIP/Info/sip_profiles_application_modify_remove_header: Header before modification : Remote-Party-ID: "The Client" <sip:62505800@10.70.13.10>;party=calling;screen=yes;privacy=off

Feb 25 04:21:42.731: //4430/DA0E14800000/SIP/Info/sip_profiles_check_and_get_variables_in_replace_pattern: substituted_replace_pattern : \

Feb 25 04:21:42.731: //4430/DA0E14800000/SIP/Info/sip_profiles_check_and_get_variables_in_replace_pattern: configured_replace_pattern : 1TheClient.com.au>\2

Feb 25 04:21:42.731: //4430/DA0E14800000/SIP/Info/sip_profiles_check_and_get_variables_in_replace_pattern: substituted_replace_pattern : \1TheClient.com.au>\

Feb 25 04:21:42.731: //4430/DA0E14800000/SIP/Info/sip_profiles_check_and_get_variables_in_replace_pattern: configured_replace_pattern : 2

Feb 25 04:21:42.731: //-1/xxxxxxxxxxxx/SIP/Info/sip_profiles_application_modify_remove_header: Header after modification : Remote-Party-ID: "The Client" <sip:62505800@TheClient.com.au>;party=calling;screen=yes;privacy=off

Feb 25 04:21:42.731: //4430/DA0E14800000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

Feb 25 04:21:42.731: //4430/DA0E14800000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0

Feb 25 04:21:42.731: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportLogicSendMsg: connection-reuse configured, listen conn-id : 2

Feb 25 04:21:42.731: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x313C83B0, addr=203.52.2.164, port=5060, local_addr=10.70.13.10, connId=2 for UDP

Feb 25 04:21:42.731: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1

Feb 25 04:21:42.731: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0

Feb 25 04:21:42.731: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog

Feb 25 04:21:42.731: //4430/DA0E14800000/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 100 Trying

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK524A05

From: "The Client" <sip:62505800@TheClient.com.au>;tag=47ACDA70-21B4

To: <sip:0444888333@TheClient.com.au>

Call-ID: B0F41AE0-7E3911E2-82D98DD1-6EB45A6B@10.70.13.10

CSeq: 101 INVITE

Timestamp: 1361766102

Feb 25 04:21:42.731: //4430/DA0E14800000/SIP/Info/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX

Feb 25 04:21:42.731: //4430/DA0E14800000/SIP/State/sipSPIChangeState: 0x2ADF2F00 : State change from (STATE_SENT_INVITE, SUBSTATE_NONE)  to (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING)

Feb 25 04:21:42.739: //4430/DA0E14800000/SIP/Msg/ccsipDisplayMsg:

Sent:

INVITE sip:0444888333@TheClient.com.au:5060 SIP/2.0

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK524A05

Remote-Party-ID: "The Client" <sip:62505800@TheClient.com.au>;party=calling;screen=yes;privacy=off

From: "The Client" <sip:62505800@TheClient.com.au>;tag=47ACDA70-21B4

To: <sip:0444888333@TheClient.com.au>

Date: Mon, 25 Feb 2013 04:21:42 GMT

Call-ID: B0F41AE0-7E3911E2-82D98DD1-6EB45A6B@10.70.13.10

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

Min-SE:  1800

Cisco-Guid: 3658355840-0000065536-0000000065-0335756298

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

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

CSeq: 101 INVITE

Timestamp: 1361766102

Contact: <sip:62505800@10.70.13.10:5060>

Expies: 300

Allow-Events: telephone-event

Max-Forwards: 69

Session-Expires:  1800

Content-Length: 0

Feb 25 04:21:42.739: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [203.52.2.164]:5060, local_address:[10.70.13.10]

Feb 25 04:21:42.739: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1

Feb 25 04:21:42.739: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0

Feb 25 04:21:42.739: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog

Feb 25 04:21:42.743: //4430/DA0E14800000/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 404 Not found

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK524A05

From: "The Client" <sip:62505800@TheClient.com.au>;tag=47ACDA70-21B4

To: <sip:0444888333@TheClient.com.au>;tag=1115929120-1361766102231

Call-ID: B0F41AE0-7E3911E2-82D98DD1-6EB45A6B@10.70.13.10

CSeq: 101 INVITE

Timestamp: 1361766102

Content-Length: 0

Feb 25 04:21:42.743: //4430/DA0E14800000/SIP/Info/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX

Feb 25 04:21:42.743: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container

Feb 25 04:21:42.743: //4430/DA0E14800000/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 1 event

Feb 25 04:21:42.743: //4430/DA0E14800000/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer:  Could not get any elements from TD Container

Feb 25 04:21:42.743: //4430/DA0E14800000/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer:  Could not get any elements from TD Container

Feb 25 04:21:42.743: //4430/DA0E14800000/SIP/Info/ccsip_offer_ans_handle_call_active:

Feb 25 04:21:42.743: //4430/DA0E14800000/SIP/Info/ccsip_offer_ans_process_event:

Feb 25 04:21:42.743: //4430/DA0E14800000/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_IDLE, event:E_SIP_DIALOG_ESTD

Feb 25 04:21:42.743: //4430/DA0E14800000/SIP/Info/ccsip_offer_ans_process_event: O/A - cnfsm ret 2

Feb 25 04:21:42.743: //4430/DA0E14800000/SIP/Info/sipSPISendAck: Associated container=0x2BB80BF4 to Ack

Feb 25 04:21:42.743: //4430/DA0E14800000/SIP/Transport/sipSPISendAck: Sending ACK to the transport layer

Feb 25 04:21:42.743: //4430/DA0E14800000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE

Feb 25 04:21:42.743: //4430/DA0E14800000/SIP/Transport/sipSPITransportSendMessage: msg=0x313C83B0, addr=203.52.2.164, port=5060, sentBy_port=0, local_addr=10.70.13.10, is_req=1, transport=1, switch=0, callBack=0x0

Feb 25 04:21:42.743: //-1/xxxxxxxxxxxx/SIP/Info/httpish_msg_get_complete_header: No holder for this header

Feb 25 04:21:42.743: //-1/xxxxxxxxxxxx/SIP/Info/sip_profiles_application_modify_remove_header: Unable to get header from stack

Feb 25 04:21:42.819: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[4433]

Feb 25 04:21:43.751: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [203.52.2.164]:5060, local_address:[10.70.13.10]

Feb 25 04:21:43.751: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1

Feb 25 04:21:43.751: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0

Feb 25 04:21:43.751: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog

Feb 25 04:21:43.751: //4430/DA0E14800000/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 404 Not found

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK524A05

From: "The Client" <sip:62505800@TheClient.com.au>;tag=47ACDA70-21B4

To: <sip:0444888333@TheClient.com.au>;tag=1115929120-1361766102231

Call-ID: B0F41AE0-7E3911E2-82D98DD1-6EB45A6B@10.70.13.10

CSeq: 101 INVITE

Timestamp: 1361766102

Content-Length: 0

Feb 25 04:21:43.755: //4430/DA0E14800000/SIP/Info/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX

Feb 25 04:21:43.755: //4430/DA0E14800000/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 1 event

Feb 25 04:21:43.755: //4430/DA0E14800000/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer:  Could not get any elements from TD Container

Feb 25 04:21:43.755: //4430/DA0E14800000/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer:  Could not get any elements from TD Container

Feb 25 04:21:43.755: //4430/DA0E14800000/SIP/Info/ccsip_offer_ans_handle_call_active:

Feb 25 04:21:43.755: //4430/DA0E14800000/SIP/Info/ccsip_offer_ans_process_event:

Feb 25 04:21:43.755: //4430/DA0E14800000/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_IDLE, event:E_SIP_DIALOG_ESTD

Feb 25 04:21:43.755: //4430/DA0E14800000/SIP/Info/ccsip_offer_ans_process_event: O/A - cnfsm ret 2

Feb 25 04:21:43.755: //4430/DA0E14800000/SIP/Info/sipSPISendAck: Associated container=0x2BB7F964 to Ack

Feb 25 04:21:43.755: //4430/DA0E14800000/SIP/Transport/sipSPISendAck: Sending ACK to the transport layer

Feb 25 04:21:43.755: //4430/DA0E14800000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE

Feb 25 04:21:43.755: //4430/DA0E14800000/SIP/Transport/sipSPITransportSendMessage: msg=0x313C83B0, addr=203.52.2.164, port=5060, sentBy_port=0, local_addr=10.70.13.10, is_req=1, transport=1, switch=0, callBack=0x0

Feb 25 04:21:43.755: //-1/xxxxxxxxxxxx/SIP/Info/httpish_msg_get_complete_header: No holder for this header

Feb 25 04:21:43.755: //-1/xxxxxxxxxxxx/SIP/Info/sip_profiles_application_modify_remove_header: Unable to get header from stack

Feb 25 04:21:43.755: //4430/DA0E14800000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

Feb 25 04:21:43.755: //4430/DA0E14800000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0

Feb 25 04:21:43.755: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportLogicSendMsg: connection-reuse configured, listen conn-id : 2

Feb 25 04:21:43.755: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x313C83B0, addr=203.52.2.164, port=5060, local_addr=10.70.13.10, connId=2 for UDP

Feb 25 04:21:43.755: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Sent:

ACK sip:0444888333@TheClient.com.au:5060 SIP/2.0

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK524A05

From: "The Client" <sip:62505800@TheClient.com.au>;tag=47ACDA70-21B4

To: <sip:0444888333@TheClient.com.au>;tag=1115929120-1361766102231

Date: Mon, 25 Feb 2013 04:21:42 GMT

Call-ID: B0F41AE0-7E3911E2-82D98DD1-6EB45A6B@10.70.13.10

Max-Forwards: 70

CSeq: 101 ACK

Allow-Events: telephone-event

Reason: Q.850;cause=1

Content-Length: 0

[Terry Cheema]

You are receiving:

Received:

SIP/2.0 404 Not found

and

Reason: Q.850;cause=1

The above messages mean Unallocated number or the remote party was unable to find a match for your dialed number.

Before looking any further can you confirm:

- 0444888333 is dialable number? Can you dial this number from your mobile?

- The calling id you are sending to your provider is correct - they may reject call if its incorrect

- Lastly if above both are good, then you may need to look into the config

Terry

[lukedp]

The Dialed by number is my mobile and i am unable to dial it.

The calling ID is the start of the range that is provided by the SIP service.

I can see the dial-peer rules being matchd then they get dropped.

[Terry Cheema]

To confirm your topology, are you using SIP trunk from CUCM to CUBE:

CUCM -(SIP Trunk?) - CUBE - SIP Trunk -ITSP

Can you post the following:

sh run | s voice service voip

sh run | s dial-peer

Make another call - and capture and post the output of debug ccsip messages.

Is your ITSP Telstra by any chance?

Terry

[lukedp]

Hi Terry,

That is correct i have 2 cucm services. 1 is a publisher the other is a subscriber. Both services have their own SIP trunk connecting to their respective Cube and from the cube each device has its own respective SIP connection to the SIP provider (Telstra).

voice service voip

ip address trusted list

  ipv4 x.x.x.x 255.255.255.255 <-- Primary CUCM

  ipv4 x.x.x.x 255.255.255.255 <-- Secondary CUCM

  ipv4 203.52.0.160 255.255.255.240

  ipv4 203.52.1.221 <--- SIP Service Provider

  ipv4 203.52.1.222 <-- SIP Service Provider

address-hiding

allow-connections sip to sip

fax protocol none

sip

  bind control source-interface Port-channel1.63

  bind media source-interface Port-channel1.63

  outbound-proxy dns:sbc-wa.nipt.telstra.com

  midcall-signaling passthru

  sip-profiles 100

!

dial-peer voice 30 voip

description ## outgoing cucm 1 ##

preference 2

destination-pattern 893383[12]..

session protocol sipv2

session target ipv4:10.60.3.20

voice-class codec 10 

no voice-class sip outbound-proxy  

dtmf-relay rtp-nte

fax protocol none

no vad

!

dial-peer voice 31 voip

description ## outgoing cucm 2 ##

preference 1

destination-pattern 893383[12]..

session protocol sipv2

session target ipv4:10.70.13.20

voice-class codec 10 

no voice-class sip outbound-proxy  

dtmf-relay rtp-nte

fax protocol none

no vad

!

dial-peer voice 35 voip

description ## incoming cucm ##

session protocol sipv2

session target sip-server

incoming called-number .T

voice-class codec 10 

no voice-class sip outbound-proxy  

dtmf-relay rtp-nte

fax protocol none

!

dial-peer voice 60 voip

description ## outgoing tipt ##

destination-pattern .T

session protocol sipv2

session target sip-server

voice-class codec 10 

voice-class sip profiles 1

dtmf-relay rtp-nte

fax protocol none

!

dial-peer voice 65 voip

description ## incoming tipt ##

rtp payload-type nse 99

session protocol sipv2

session target sip-server

incoming called-number 893383[12]..

voice-class codec 10 

voice-class sip dtmf-relay force rtp-nte

dtmf-relay rtp-nte

fax protocol none

!

!

[Terry Cheema · Accepted solution]

Hi - Can you also make another test call and post the output of debug ccsip messages ?

Also if you can do the following before making call:

voice service voip

no ip address trusted authenticate

(I am seeing your CUBE talk to 203.52.2.164 which is not in your trusted list)

Terry    

[lukedp]

Hi Terry,

I have obscured the numbers for privacy but they are matching on the dial-peeers

INVITE sip:862550000@10.70.13.10:5060 SIP/2.0

Via: SIP/2.0/UDP 203.52.2.164:5060;branch=z9hG4bKkud3lf30eg9104tfi141.1

From: <892224433>;tag=1313379916-1361845589158-

To: "862550000 862550000"<>862550000@TheClient.com,au.com.au;url-cookie=VNWEHA1-lj1dn3k5t840e>

Call-ID: BW132629158260213-981171764@10.83.154.147

CSeq: 170478164 INVITE

Contact: <892224433>

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

Accept: application/media_control+xml,application/sdp,multipart/mixed

Supported:

Max-Forwards: 29

Content-Type: application/sdp

Content-Length: 422

v=0

o=BroadWorks 943513346 1 IN IP4 203.52.2.164

s=-

c=IN IP4 203.52.2.164

t=0 0

a=media-release:hngl5rp9pujvivh05pvumib1j8jovg8o6u7k8gsnmkmj2844l4v1004042

a=media-release-con-addr:d6v1k1hvmhvh1081o9j0

m=audio 19354 RTP/AVP 8 18 0 101

a=ptime:20

a=rtpmap:8 PCMA/8000

a=rtpmap:18 G729/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=fmtp:18 annexb=no

a=silenceSupp:off - - - -

Feb 26 02:26:29.172: //52/C2E79BD28086/SIP/Msg/ccsipDisplayMsg:

Sent:

SIP/2.0 100 Trying

Via: SIP/2.0/UDP 203.52.2.164:5060;branch=z9hG4bKkud3lf30eg9104tfi141.1

From: <892224433>;tag=1313379916-1361845589158-

To: "862550000 862550000"<>862550000@TheClient.com,au.com.au;url-cookie=VNWEHA1-lj1dn3k5t840e>

Date: Tue, 26 Feb 2013 02:26:29 GMT

Call-ID: BW132629158260213-981171764@10.83.154.147

CSeq: 170478164 INVITE

Allow-Events: telephone-event

Server: Cisco-SIPGateway/IOS-12.x

Content-Length: 0

Feb 26 02:26:29.172: //53/C2E79BD28086/SIP/Msg/ccsipDisplayMsg:

Sent:

INVITE sip:862550000@10.60.3.20:5060 SIP/2.0

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK2BCD

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

From: <>892224433@TheClient.com,au.com.au>;tag=324738-FE3

To: <862550000>

Date: Tue, 26 Feb 2013 02:26:29 GMT

Call-ID: C2E837FA-7EF211E2-808C9BC5-9698E19A@10.70.13.10

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

Min-SE:  1800

Cisco-Guid: 3269958610-2129793506-2156305349-2526601626

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

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

CSeq: 101 INVITE

Timestamp: 1361845589

Contact: <892224433>

Expires: 300

Allow-Events: telephone-event

Max-Forwards: 28

Content-Type: application/sdp

Content-Disposition: session;handling=required

Content-Length: 305

v=0

o=CiscoSystemsSIP-GW-UserAgent 2495 8249 IN IP4 10.70.13.10

s=SIP Call

c=IN IP4 203.52.2.164

t=0 0

m=audio 19354 RTP/AVP 8 18 0 101

c=IN IP4 203.52.2.164

a=rtpmap:8 PCMA/8000

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:0 PCMU/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

Feb 26 02:26:29.176: //53/C2E79BD28086/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 100 Trying

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK2BCD

From: <>892224433@TheClient.com,au.com.au>;tag=324738-FE3

To: <862550000>

Date: Tue, 26 Feb 2013 02:26:29 GMT

Call-ID: C2E837FA-7EF211E2-808C9BC5-9698E19A@10.70.13.10

CSeq: 101 INVITE

Allow-Events: presence

Content-Length: 0

Feb 26 02:26:29.188: //53/C2E79BD28086/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 180 Ringing

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK2BCD

From: <>892224433@TheClient.com,au.com.au>;tag=324738-FE3

To: <862550000>;tag=181~a928f5a0-237e-4cbd-9716-954b915b4a58-24191169

Date: Tue, 26 Feb 2013 02:26:29 GMT

Call-ID: C2E837FA-7EF211E2-808C9BC5-9698E19A@10.70.13.10

CSeq: 101 INVITE

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

Allow-Events: presence

Supported: X-cisco-srtp-fallback

Supported: Geolocation

Contact: <862550000>

Content-Length: 0

Feb 26 02:26:29.192: //52/C2E79BD28086/SIP/Msg/ccsipDisplayMsg:

Sent:

SIP/2.0 180 Ringing

Via: SIP/2.0/UDP 203.52.2.164:5060;branch=z9hG4bKkud3lf30eg9104tfi141.1

From: <892224433>;tag=1313379916-1361845589158-

To: "862550000 862550000"<>862550000@TheClient.com,au.com.au;url-cookie=VNWEHA1-lj1dn3k5t840e>;tag=324748-10F9

Date: Tue, 26 Feb 2013 02:26:29 GMT

Call-ID: BW132629158260213-981171764@10.83.154.147

CSeq: 170478164 INVITE

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

Allow-Events: telephone-event

Remote-Party-ID: <862550000>;party=called;screen=no;privacy=off

Contact: <862550000>

Server: Cisco-SIPGateway/IOS-12.x

Content-Length: 0

Feb 26 02:26:29.260: //53/C2E79BD28086/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 503 Service Unavailable

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK2BCD

From: <>892224433@TheClient.com,au.com.au>;tag=324738-FE3

To: <862550000>;tag=181~a928f5a0-237e-4cbd-9716-954b915b4a58-24191169

Date: Tue, 26 Feb 2013 02:26:29 GMT

Call-ID: C2E837FA-7EF211E2-808C9BC5-9698E19A@10.70.13.10

CSeq: 101 INVITE

Allow-Events: presence

Reason: Q.850;cause=47

Content-Length: 0

Feb 26 02:26:29.264: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Sent:

ACK sip:862550000@10.60.3.20:5060 SIP/2.0

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK2BCD

From: <>892224433@TheClient.com,au.com.au>;tag=324738-FE3

To: <862550000>;tag=181~a928f5a0-237e-4cbd-9716-954b915b4a58-24191169

Date: Tue, 26 Feb 2013 02:26:29 GMT

Call-ID: C2E837FA-7EF211E2-808C9BC5-9698E19A@10.70.13.10

Max-Forwards: 70

CSeq: 101 ACK

Allow-Events: telephone-event

Content-Length: 0

Feb 26 02:26:29.264: //54/C2E79BD28086/SIP/Msg/ccsipDisplayMsg:

Sent:

INVITE sip:862550000@10.70.3.20:5060 SIP/2.0

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK2C20AC

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

From: <>892224433@TheClient.com,au.com.au>;tag=324794-84D

To: <862550000>

Date: Tue, 26 Feb 2013 02:26:29 GMT

Call-ID: C2F6415B-7EF211E2-808E9BC5-9698E19A@10.70.13.10

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

Min-SE:  1800

Cisco-Guid: 3269958610-2129793506-2156305349-2526601626

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

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

CSeq: 101 INVITE

Timestamp: 1361845589

Contact: <892224433>

Expires: 300

Allow-Events: telephone-event

Max-Forwards: 28

Content-Type: application/sdp

Content-Disposition: session;handling=required

Content-Length: 305

v=0

o=CiscoSystemsSIP-GW-UserAgent 4733 6824 IN IP4 10.70.13.10

s=SIP Call

c=IN IP4 203.52.2.164

t=0 0

m=audio 19354 RTP/AVP 8 18 0 101

c=IN IP4 203.52.2.164

a=rtpmap:8 PCMA/8000

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:0 PCMU/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

Feb 26 02:26:29.764: //54/C2E79BD28086/SIP/Msg/ccsipDisplayMsg:

Sent:

INVITE sip:862550000@10.70.3.20:5060 SIP/2.0

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK2C20AC

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

From: <>892224433@TheClient.com,au.com.au>;tag=324794-84D

To: <862550000>

Date: Tue, 26 Feb 2013 02:26:29 GMT

Call-ID: C2F6415B-7EF211E2-808E9BC5-9698E19A@10.70.13.10

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

Min-SE:  1800

Cisco-Guid: 3269958610-2129793506-2156305349-2526601626

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

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

CSeq: 101 INVITE

Timestamp: 1361845589

Contact: <892224433>

Expires: 300

Allow-Events: telephone-event

Max-Forwards: 28

Content-Type: application/sdp

Content-Disposition: session;handling=required

Content-Length: 305

v=0

o=CiscoSystemsSIP-GW-UserAgent 4733 6824 IN IP4 10.70.13.10

s=SIP Call

c=IN IP4 203.52.2.164

t=0 0

m=audio 19354 RTP/AVP 8 18 0 101

c=IN IP4 203.52.2.164

a=rtpmap:8 PCMA/8000

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:0 PCMU/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

Feb 26 02:26:30.764: //54/C2E79BD28086/SIP/Msg/ccsipDisplayMsg:

Sent:

INVITE sip:862550000@10.70.3.20:5060 SIP/2.0

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK2C20AC

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

From: <>892224433@TheClient.com,au.com.au>;tag=324794-84D

To: <862550000>

Date: Tue, 26 Feb 2013 02:26:30 GMT

Call-ID: C2F6415B-7EF211E2-808E9BC5-9698E19A@10.70.13.10

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

Min-SE:  1800

Cisco-Guid: 3269958610-2129793506-2156305349-2526601626

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

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

CSeq: 101 INVITE

Timestamp: 1361845590

Contact: <892224433>

Expires: 300

Allow-Events: telephone-event

Max-Forwards: 28

Content-Type: application/sdp

Content-Disposition: session;handling=required

Content-Length: 305

v=0

o=CiscoSystemsSIP-GW-UserAgent 4733 6824 IN IP4 10.70.13.10

s=SIP Call

c=IN IP4 203.52.2.164

t=0 0

m=audio 19354 RTP/AVP 8 18 0 101

c=IN IP4 203.52.2.164

a=rtpmap:8 PCMA/8000

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:0 PCMU/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

Feb 26 02:26:32.764: //55/C2E79BD28086/SIP/Msg/ccsipDisplayMsg:

Sent:

INVITE sip:862550000@TheClient.com,au.com.au:5060 SIP/2.0

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK2D18F4

Remote-Party-ID: <>892224433@TheClient.com,au.com.au>;party=calling;screen=no;privacy=off

From: <>892224433@TheClient.com,au.com.au>;tag=325540-201E

To: <>862550000@TheClient.com,au.com.au>

Date: Tue, 26 Feb 2013 02:26:32 GMT

Call-ID: C50C517B-7EF211E2-80909BC5-9698E19A@10.70.13.10

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

Min-SE:  1800

Cisco-Guid: 3269958610-2129793506-2156305349-2526601626

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

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

CSeq: 101 INVITE

Timestamp: 1361845592

Contact: <892224433>

Expires: 300

Allow-Events: telephone-event

Max-Forwards: 28

Content-Type: application/sdp

Content-Disposition: session;handling=required

Content-Length: 329

v=0

o=CiscoSystemsSIP-GW-UserAgent 4725 4003 IN IP4 10.70.13.10

s=SIP Call

c=IN IP4 203.52.2.164

t=0 0

m=audio 19354 RTP/AVP 8 18 0 101 19

c=IN IP4 203.52.2.164

a=rtpmap:8 PCMA/8000

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:0 PCMU/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=rtpmap:19 CN/8000

Feb 26 02:26:32.772: //55/C2E79BD28086/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 100 Trying

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK2D18F4

From: <>892224433@TheClient.com,au.com.au>;tag=325540-201E

To: <>862550000@TheClient.com,au.com.au>

Call-ID: C50C517B-7EF211E2-80909BC5-9698E19A@10.70.13.10

CSeq: 101 INVITE

Timestamp: 1361845592

Feb 26 02:26:32.832: //55/C2E79BD28086/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 404 Not found

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK2D18F4

From: <>892224433@TheClient.com,au.com.au>;tag=325540-201E

To: <>862550000@TheClient.com,au.com.au>;tag=227600251-1361845592821

Call-ID: C50C517B-7EF211E2-80909BC5-9698E19A@10.70.13.10

CSeq: 101 INVITE

Timestamp: 1361845592

Content-Length: 0

Feb 26 02:26:32.832: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Sent:

ACK sip:862550000@TheClient.com,au.com.au:5060 SIP/2.0

Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK2D18F4

From: <>892224433@TheClient.com,au.com.au>;tag=325540-201E

To: <>862550000@TheClient.com,au.com.au>;tag=227600251-1361845592821

Date: Tue, 26 Feb 2013 02:26:32 GMT

Call-ID: C50C517B-7EF211E2-80909BC5-9698E19A@10.70.13.10

Max-Forwards: 70

CSeq: 101 ACK

Allow-Events: telephone-event

Content-Length: 0

Feb 26 02:26:32.832: //52/C2E79BD28086/SIP/Msg/ccsipDisplayMsg:

Sent:

SIP/2.0 404 Not Found

Via: SIP/2.0/UDP 203.52.2.164:5060;branch=z9hG4bKkud3lf30eg9104tfi141.1

From: <892224433>;tag=1313379916-1361845589158-

To: "862550000 862550000"<>862550000@TheClient.com,au.com.au;url-cookie=VNWEHA1-lj1dn3k5t840e>;tag=324748-10F9

Date: Tue, 26 Feb 2013 02:26:29 GMT

Call-ID: BW132629158260213-981171764@10.83.154.147

CSeq: 170478164 INVITE

Allow-Events: telephone-event

Server: Cisco-SIPGateway/IOS-12.x

Reason: Q.850;cause=1

Content-Length: 0

Feb 26 02:26:32.836: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Received:

ACK sip:862550000@10.70.13.10:5060 SIP/2.0

Via: SIP/2.0/UDP 203.52.2.164:5060;branch=z9hG4bKkud3lf30eg9104tfi141.1

CSeq: 170478164 ACK

From: <892224433>;tag=1313379916-1361845589158-

To: "862550000 862550000"<>862550000@TheClient.com,au.com.au;url-cookie=VNWEHA1-lj1dn3k5t840e>;tag=324748-10F9

Call-ID: BW132629158260213-981171764@10.83.154.147

Max-Forwards: 29

Content-Length: 0

[Terry Cheema]

Luke - I will look into the logs as soon as I can - Can you confirm one more thing, are you binding the SIP to correct interface/ip address? Is it the same ip address what you specified in CUCM SIP trunk destination?

[lukedp]

I have just resolved this issuse.

It appears that an incorrect configuration was sent to me by the SIP provider. I am able to make calls in out  and know i can recieve audio.

Thankyou for you help Terry

[Terry Cheema]

Great - Not a problem - Can you share what needed correction - was it the wrong trust list address?

By the way you were getting:

Received:
SIP/2.0 503 Service Unavailable     <<<<<

After that SIP invite was being re-sent and ended up getting:

Received:
SIP/2.0 404 Not found
Via: SIP/2.0/UDP 10.70.13.10:5060;branch=z9hG4bK2D18F4

Terry

[lukedp]

Hi Terry,

I amended the ipv4 trusted listed to add my states local sip service

I removed the media flow-through command under voice service voip.

The 503 message was due to the test IP Phone not being pluged in, this was not the issue at the other time of testing.

[Terry Cheema]

Cool - Glad everything is working! See you around.

Terry