[cisco-voip] CUBE and MS Lync

Erick Wellnitz ewellnitzvoip at gmail.com
Tue Aug 21 13:52:18 EDT 2012


IOS version c3845-advipservicesk9-mz.151-4.M4, CM 6.1.3, Lync 2010

We are only initiating calls from CUCM currently.

I have used this document as a template:
http://www.cisco.com/en/US/solutions/collateral/ns340/ns414/ns728/ns784/8464511.pdf

Okay...I have my CUBE set up as follows:
voice-card 0
dspfarm
dsp services dspfarm
!
!
!
voice service voip
allow-connections sip to sip
signaling forward none
sip
session transport tcp
header-passing
asserted-id pai
history-info
midcall-signaling passthru
privacy-policy passthru
!
voice class sip-profiles 3
request INVITE sip-header Diversion remove
!
sccp local GigabitEthernet0/0
sccp ccm 10.#.#.# identifier 1 priority 1 version 4.0
sccp
!
sccp ccm group 1
associate ccm 1 priority 1
associate profile 1 register LyncTranscode1
!
dspfarm profile 1 transcode
codec g729br8
codec g729abr8
codec g729ar8
codec g711alaw
codec g729r8
codec g711ulaw
maximum sessions 96
associate application SCCP
!
dial-peer voice 1000 voip
description from Cisco UCM to Lync outbound dial-peer
destination-pattern 3109
session protocol sipv2
 session target ipv4:10.#.#.#:5068
session transport tcp
voice-class sip early-offer forced
voice-class sip profiles 3
voice-class sip block 183 sdp present
dtmf-relay rtp-nte
codec g711ulaw
!
dial-peer voice 1001 voip
description from Cisco UCM to Lync inbound dial-peer
session protocol sipv2
incoming called-number 3109
dtmf-relay rtp-nte
!
telephony-service
sdspfarm units 1
sdspfarm transcode sessions 128
sdspfarm tag 1 LyncTranscode1
max-ephones 1
max-dn 2
 ip source-address 10.#.#.# port 2000
max-conferences 12 gain -6
transfer-system full-consult
 create cnf-files version-stamp XXXX

I have my SIP trunk pointed at the CUBE but I get a 403 Forbidden error
when I try to make a call.  From the ccsip debugs it looks like I'm having
media negotiation issues even though my regions are set correctly.

Could anyone shed some light on where I am going wrong?

Thanks!
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20120821/e8b4cf82/attachment.html>
-------------- next part --------------
*Aug 21 17:15:04.539: //-1/xxxxxxxxxxxx/SIP/Info/sip_tcp_sockerror_to_spi: Sending TCP Remote Closure to SPI, connid: 2
*Aug 21 17:15:04.539: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 55
*Aug 21 17:15:04.539: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWSocketException: context=0x0
*Aug 21 17:15:04.539: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessSocketExceptions: gConnTab=0x70DD6E9C, addr=10.12.90.211, port=59432, local_addr=, connid=2, transport=TCP
*Aug 21 17:15:04.539: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostCloseConnection: Posting TCP conn close for addr=10.12.90.211, port=59432, local_addr=, connid=2
*Aug 21 17:15:04.539: //-1/xxxxxxxxxxxx/SIP/Transport/sipDeleteConnInstance: Deleted conn=0x69341C8C, connid=2, addr=10.12.90.211, port=59432, local_addr=, transport=TCP
*Aug 21 17:15:04.539: //-1/xxxxxxxxxxxx/SIP/Info/sip_tcp_purge_entry: Socket fd: 1 closed for connid 2 with address: 10.12.90.211, remote port: 59432
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x70DD6E9C, addr=10.8.50.104, port=59666, local_addr=, connid=3, transport=TCP
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received: 
INVITE sip:3109 at 10.12.52.50:5060 SIP/2.0
Date: Tue, 21 Aug 2012 17:17:37 GMT
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, PUBLISH
From: "Erick Wellnitz" <sip:3704 at 10.8.50.104>;tag=c36834e3-4605-44f0-a4ef-d172a6e7d1c7-96522661
Allow-Events: presence
Supported: timer,replaces
Min-SE:  1800
Remote-Party-ID: "Erick Wellnitz" <sip:3704 at 10.8.50.104>;party=calling;screen=yes;privacy=off
Content-Length: 0
User-Agent: Cisco-CUCM6.1
To: <sip:3109 at 10.12.52.50>
Contact: <sip:3704 at 10.8.50.104:5060;transport=tcp>
Expires: 180
Call-ID: 19565400-331c2b1-1adb-6832080a at 10.8.50.104
Via: SIP/2.0/TCP 10.8.50.104:5060;branch=z9hG4bK392f9086e6
CSeq: 101 INVITE
Session-Expires:  1800
Max-Forwards: 70


*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0xC3287CA8) with key=[5878] to table
*Aug 21 17:15:05.535: //-1/000000000000/SIP/Info/ccsip_offer_ans_init: 
*Aug 21 17:15:05.535: //-1/000000000000/SIP/Info/ccsip_iwf_init:  
*Aug 21 17:15:05.535: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init: 
*Aug 21 17:15:05.535: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.8.50.104,Port 59666, Transport 2, SentBy Port 5060
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.12.52.50
*Aug 21 17:15:05.535: //-1/95DCF3969719/SIP/State/sipSPIChangeState: 0xC3287CA8 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.8.50.104,Port 59666, Transport 2, SentBy Port 5060
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CST to SIP default timezone = GMT
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.8.50.104,Port 59666, Transport 2, SentBy Port 5060
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.12.52.50
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckIpip: VOIP dialpeer (peer=0x68233C6C) found for sip_user: 3109
*Aug 21 17:15:05.535: //-1/95DCF3969719/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done
*Aug 21 17:15:05.535: //-1/95DCF3969719/SIP/Info/sipSPISetInfoFromRpid: Received current remote name: Erick Wellnitz, current remote number: 3704
*Aug 21 17:15:05.535: //-1/95DCF3969719/SIP/Info/sipSPISetInfoFromRpid: Received ;screen=yes ;privacy=off -> Setting Octet3A 0x81, extended_privacy 0x00
*Aug 21 17:15:05.535: //-1/95DCF3969719/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
*Aug 21 17:15:05.535: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCSTA: No CSTA found in inbound container
*Aug 21 17:15:05.535: //-1/95DCF3969719/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0xC3287CA8 key=19565400-331c2b1-1adb-6832080a at 10.8.50.1043109
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 3109
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 3704
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name Erick Wellnitz, number 3704, Calling oct3 0x00, oct_3a 0x81, Called number 3109
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:10.8.50.104:5060, Host:10.8.50.104
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 3704
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIGetCallConfig: Peer tag 1001 matched for incoming call
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
*Aug 21 17:15:05.539: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
*Aug 21 17:15:05.539: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
*Aug 21 17:15:05.539: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.12.52.50
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIGetCallConfig: Checking Video Type Rate=-1 video_codec_allowed=1F
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIGetCallConfig: Media forking disabled
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIContinueNewMsgInvite: Calling name Erick Wellnitz, number 3704, Calling oct3 0x00, oct_3a 0x81, ext_priv 0x00, Called number 3109, oct3 0x00
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIValidateRequestUri: Not Enabled
*Aug 21 17:15:05.539: //-1/95DCF3969719/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/sipSPI_ipip_IsSDPPassthruEnabled:  - 0
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:0, container:C36CA9D8
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr: 
Session-Expires value: 1800 refresher: none
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/Session-Timer/sipSTSLExtractMinSEHdr: Min-SE Duration: 1800
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/Session-Timer/sipSTSLInitialSRReqPeerEventGen: sending received session expires to the peer leg
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_PASS_ST_PARAMS, SE Value:1800, SE Refresher:none, Min-SE Value:1800, flags:2001
*Aug 21 17:15:05.539: //5868/95DCF3969719/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
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found
*Aug 21 17:15:05.539: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentSDP: No SDP found in inbound container
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/sipSPIDoQoSNegotiationWithNoMediaLine: Local Precondition: 1, Remote Precondition: 1
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/sip_iwf_def_copy_sdp_to_channelInfo: 
CallID 5868, sdp 0x692B8BEC channels 0xC32892FC
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Delayed media case...creating new stream
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1
*Aug 21 17:15:05.539: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop()
*Aug 21 17:15:05.539: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address()
*Aug 21 17:15:05.539: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 10.12.52.50
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.12.52.50
*Aug 21 17:15:05.539: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 18416 for stream 1
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=18416
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Media/sipSPIAddSDPMediaPayload: Preferred method of dtmf relay is: 6, with payload: 101
*Aug 21 17:15:05.539: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729r8 codecbytes :20, ptime: 20
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = 19565400-331c2b1-1adb-6832080a at 10.8.50.104
*Aug 21 17:15:05.539: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found
*Aug 21 17:15:05.539: //5868/95DCF3969719/SIP/Info/ccsip_api_call_setup_ind: Headers from INVITE added to callInfo container
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Unsupported header passthru is not configured and no headers are present in hdr_hash_queue
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled:  - 0
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Not Enabled
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/ccsip_api_call_setup_ind: Unable to add unsupp headers to container
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/ccsip_api_call_setup_ind: Set Protocol information
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 24
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured 
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPI_ipip_store_channel_info: negotiated dtmf not available, using dialpeer config dtmf = 6
*Aug 21 17:15:05.543: //5868/95DCF3969719/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 :0
          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.12.52.50]:18416
          Media Dest Addr/Port   : [ - ]:0

*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPI_ipip_calculate_channel_count: Number of streams to report = 0
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPI_ipip_store_channel_info: Setting CHANNEL_COUNT = 0 for callid 5868
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPIShrlCall: Check peer: 1001 for Shared-Line call, callid: 5868
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/ccsip_set_bearer_capability: 
   Bearer Capability: Speech (0x00)
*Aug 21 17:15:05.543: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
*Aug 21 17:15:05.543: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
*Aug 21 17:15:05.543: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message

*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS_DELAYED_MEDIA
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 16EC to table
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPIUpdateCallEntry: 
Call 5868 set InfoType to SPEECH
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:100, container:C36CA508
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/Session-Timer/sipSTSLValidateSessRefreshMsg: Ignoring 1xx response for session timer processing
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPISendInviteResponse: Associated container=0xC36CA508 to Invite Response 100
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Transport/sipSPITransportSendMessage: msg=0x70314B54, addr=10.8.50.104, port=59666, sentBy_port=5060, local_addr=, is_req=0, transport=2, switch=0, callBack=0x0
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Aug 21 17:15:05.543: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x70314B54, addr=10.8.50.104, port=59666, local_addr=, connId=3 for TCP
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/State/sipSPIChangeState: 0xC3287CA8 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (STATE_RECD_INVITE, SUBSTATE_NONE)
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/sipSPIProcessContactInfo: Previous Hop 10.8.50.104:5060
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Msg/ccsipDisplayMsg:
Sent: 
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 10.8.50.104:5060;branch=z9hG4bK392f9086e6
From: "Erick Wellnitz" <sip:3704 at 10.8.50.104>;tag=c36834e3-4605-44f0-a4ef-d172a6e7d1c7-96522661
To: <sip:3109 at 10.12.52.50>
Date: Tue, 21 Aug 2012 17:15:05 GMT
Call-ID: 19565400-331c2b1-1adb-6832080a at 10.8.50.104
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0


*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call.
*Aug 21 17:15:05.543: //5868/95DCF3969719/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 26
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured 
*Aug 21 17:15:05.547: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
*Aug 21 17:15:05.547: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/Info/act_recdinvite_disconnect: Performing disconnect
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table.
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0xC3287CA8 key=19565400-331c2b1-1adb-6832080a at 10.8.50.104DFE2120-1EB4
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:403, container:C36CAAE0
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/Info/Session-Timer/sipSTSLMain: 
        SE: 1800;refresher:none peer refresher:none, flags:1, posted event:E_STSL_INVALID_PEER_EVENT, reason:4
        Configured SE:1800, Configured Min-SE:1800
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/Info/sipSPISendInviteResponse: Associated container=0xC36CAAE0 to Invite Response 403
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/Transport/sipSPITransportSendMessage: msg=0x693F70D8, addr=10.8.50.104, port=59666, sentBy_port=5060, local_addr=, is_req=0, transport=2, switch=0, callBack=0x61BEEA90
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Aug 21 17:15:05.547: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x693F70D8, addr=10.8.50.104, port=59666, local_addr=, connId=3 for TCP
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/Info/sentErrResDisconnecting: Sent an 3456XX Error Response
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/State/sipSPIChangeState: 0xC3287CA8 : State change from (STATE_RECD_INVITE, SUBSTATE_NONE)  to (STATE_DISCONNECTING, SUBSTATE_NONE)
*Aug 21 17:15:05.547: //5868/95DCF3969719/SIP/Msg/ccsipDisplayMsg:
Sent: 
SIP/2.0 403 Forbidden
Via: SIP/2.0/TCP 10.8.50.104:5060;branch=z9hG4bK392f9086e6
From: "Erick Wellnitz" <sip:3704 at 10.8.50.104>;tag=c36834e3-4605-44f0-a4ef-d172a6e7d1c7-96522661
To: <sip:3109 at 10.12.52.50>;tag=DFE2120-1EB4
Date: Tue, 21 Aug 2012 17:15:05 GMT
Call-ID: 19565400-331c2b1-1adb-6832080a at 10.8.50.104
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Reason: Q.850;cause=21
Content-Length: 0


*Aug 21 17:15:05.547: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Aug 21 17:15:05.547: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
*Aug 21 17:15:05.547: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x70DD6E9C, addr=10.8.50.104, port=59666, local_addr=, connid=3, transport=TCP
*Aug 21 17:15:05.547: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received: 
ACK sip:3109 at 10.12.52.50:5060 SIP/2.0
Date: Tue, 21 Aug 2012 17:17:37 GMT
From: "Erick Wellnitz" <sip:3704 at 10.8.50.104>;tag=c36834e3-4605-44f0-a4ef-d172a6e7d1c7-96522661
Allow-Events: presence
Content-Length: 0
To: <sip:3109 at 10.12.52.50>;tag=DFE2120-1EB4
Call-ID: 19565400-331c2b1-1adb-6832080a at 10.8.50.104
Via: SIP/2.0/TCP 10.8.50.104:5060;branch=z9hG4bK392f9086e6
CSeq: 101 ACK
Max-Forwards: 70


*Aug 21 17:15:05.547: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0xC3287CA8
*Aug 21 17:15:05.551: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 10.8.50.104,Port 59666, Transport 2, SentBy Port 5060
*Aug 21 17:15:05.551: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CST to SIP default timezone = GMT
*Aug 21 17:15:05.551: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 10.8.50.104,Port 59666, Transport 2, SentBy Port 5060
*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Info/sipSPIIcpifUpdate: CallState: 2 Playout: 0 DiscTime:23475843 ConnTime 0
*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/State/sipSPIChangeState: 0xC3287CA8 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE)  to (STATE_DEAD, SUBSTATE_NONE)
*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Call/sipSPICallInfo: 
The Call Setup Information is:
Call Control Block (CCB) : 0xC3287CA8
State of The Call        : STATE_DEAD
TCP Sockets Used         : YES
Calling Number           : 3704
Called Number            : 3109
Source IP Address (Sig  ): 10.12.52.50
Destn SIP Req Addr:Port  : 10.8.50.104:5060
Destn SIP Resp Addr:Port : 10.8.50.104:59666
Destination Name         : 10.8.50.104

*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Call/sipSPIMediaCallInfo: 
Number of Media Streams: 1
Media Stream             : 1
Negotiated Codec         : No Codec   
Negotiated Codec Bytes   : 0
Nego. Codec payload      : 255 (tx), 255 (rx)
Negotiated Dtmf-relay    : 0
Dtmf-relay Payload       : 0 (tx), 0 (rx)
Source IP Address (Media): 10.12.52.50
Source IP Port    (Media): 18416
Destn  IP Address (Media):  - 
Destn  IP Port    (Media): 0
Orig Destn IP Address:Port (Media): [ - ]:0

*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Call/sipSPICallInfo: 
Disconnect Cause (CC)    : 21
Disconnect Cause (SIP)   : 403

*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 16EC
*Aug 21 17:15:05.551: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[5878] removed.
*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0xC3287CA8 key=19565400-331c2b1-1adb-6832080a at 10.8.50.1043109
*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0xC3287CA8 key=19565400-331c2b1-1adb-6832080a at 10.8.50.104DFE2120-1EB4
*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Info/ccsip_offer_ans_delete: 
*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Info/ccsip_iwf_delete:  
*Aug 21 17:15:05.551: //5868/95DCF3969719/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb C3287CA8
*Aug 21 17:15:05.551: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[5878]


More information about the cisco-voip mailing list