Nov 24 17:01:24.478: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.0.2.52]:5060, local_address:[ - ] Nov 24 17:01:24.478: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Nov 24 17:01:24.478: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0 Nov 24 17:01:24.478: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Received: INVITE sip:447777123456@10.0.0.2:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.2.52:5060;branch=z9hG4bK12768f77bfbaa8 From: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 To: Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 Supported: timer,resource-priority,replaces Min-SE: 1800 User-Agent: Cisco-CUCM9.1 Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY CSeq: 101 INVITE Expires: 180 Allow-Events: presence, kpml Supported: X-cisco-srtp-fallback,X-cisco-original-called Call-Info: ;method="NOTIFY;Event=telephone-event;Duration=500" Cisco-Guid: 2217611136-0000065536-0000185440-0872546314 Session-Expires: 7200 P-Asserted-Identity: "OrbTalk 0100" Remote-Party-ID: "OrbTalk 0100" ;party=calling;screen=yes;privacy=off Contact: Max-Forwards: 70 Content-Type: application/sdp Content-Length: 305 v=0 o=CiscoSystemsCCM-SIP 2695074 1 IN IP4 10.0.2.52 s=SIP Call c=IN IP4 10.0.0.2 b=TIAS:64000 b=AS:64 t=0 0 m=audio 16420 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=ptime:20 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:18 G729/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Nov 24 17:01:24.478: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Nov 24 17:01:24.482: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x328E4588) with key=[57] to table Nov 24 17:01:24.482: //-1/000000000000/SIP/Info/ccsip_offer_ans_init: Nov 24 17:01:24.482: //-1/000000000000/SIP/Info/ccsip_iwf_init: Nov 24 17:01:24.482: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init: Nov 24 17:01:24.482: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization: Entry... Nov 24 17:01:24.482: //-1/000000000000/SIP/Info/ccsip_ipip_media_forking_init: MF: Queue is initialised.. Nov 24 17:01:24.482: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.0.2.52,Port 5060, Transport 1, SentBy Port 5060 Nov 24 17:01:24.482: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop() Nov 24 17:01:24.482: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: ip_best_local_address 10.0.0.2 for SIP Nov 24 17:01:24.482: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.0.0.2 Nov 24 17:01:24.482: //-1/842E0F800002/SIP/State/sipSPIChangeState: 0x328E4588 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) Nov 24 17:01:24.482: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.0.2.52,Port 5060, Transport 1, SentBy Port 5060 Nov 24 17:01:24.482: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone ASD to SIP default timezone = GMT Nov 24 17:01:24.482: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.0.2.52,Port 5060, Transport 1, SentBy Port 5060 Nov 24 17:01:24.482: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckIpip: VOIP dialpeer (peer=0x2AF1EF7C) found for sip_user: 447777123456 Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIUpdateIdentity: MF: PAI url is present & make a copy.. Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIUpdateIdentity: SIP->PSTN: Setting Calling Name to OrbTalk 0100 Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIUpdateIdentity: PAI genUrl is prresent.. Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIUpdateIdentity: SIP->PSTN: Setting Calling Number to 441215550123 Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIUpdateIdentity: PAI host = 10.0.2.52 Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done Nov 24 17:01:24.482: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container Nov 24 17:01:24.482: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCSTA: No CSTA found in inbound container Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table. Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x328E4588 key=842e0f80-47316464-31346-3402000a@10.0.2.52447777123456 Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 447777123456 Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 441215550123 Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name OrbTalk 0100, number 441215550123, Calling oct3 0x00, oct_3a 0x81, Called number 447777123456 Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:10.0.2.52:5060, Host:10.0.2.52 Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 441215550123 Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIGetCallConfig: Peer tag 9011 matched for incoming call Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header Nov 24 17:01:24.482: //-1/xxxxxxxxxxxx/SIP/Info/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 ext.ext.ext.ext for SIP Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/resolve_sig_ip_address_to_bind: signaling bind address : ext.ext.ext.ext Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled Nov 24 17:01:24.482: //-1/842E0F800002/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPIGetCallConfig: Checking Video Type Rate=-1 video_codec_allowed=1F Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0 Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPIGetModemConfig: From Config: Modem NSE payload = 100, Passthrough = 4, Modem relay = 0, Gw-Xid = 1 SPRT latency 200, SPRT Retries = 12, Dict Size = 1024 String Len = 32, Compress dir = 3 Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Error/ccsip_ipip_media_forking_update_preferred_codec: MF: Not a Forked SIP leg.. Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPIGetCallConfig: Incoming: No defer BYE for last call stats Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPIGetCallConfig: Media forking disabled Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/ccsip_ipip_media_forking_anchor_leg_config: MF: en_p->encap_s.voIP.voipPeerCfgMediaClass = 0 Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/ccsip_ipip_media_forking_anchor_leg_config: MF: Dial-peer has no media class recorder. Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPIMFChangeState: MF: Prev state = 0 & New state = -1 Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/ccsip_ipip_media_forking_anchor_leg_reset: MF: Anchor leg config reset done... Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/ccsipInitDSCPPolicyInfo: No DSCP Profile configured, No RPH 2 DSCP Mapping and DSCP policing Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPIGetCallConfig: Initilise the DSCP policy Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:2 tag:0 Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0 Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Error/sipSPI_ipip_build_consolidated_header_list: No headers associated with passthrulist tag: 0 and copylist tag: 0 Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPIContinueNewMsgInvite: Calling name OrbTalk 0100, number 441215550123, Calling oct3 0x00, oct_3a 0x81, ext_priv 0x00, Called number 447777123456, oct3 0x00 Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPIValidateRequestUri: Not Enabled Nov 24 17:01:24.486: //-1/842E0F800002/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPI_ipip_IsSDPPassthruEnabled: - 0 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ Nov 24 17:01:24.486: //63/842E0F800002/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:0, container:32B05824 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr: Session-Expires value: 7200 refresher: none Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/Session-Timer/sipSTSLExtractMinSEHdr: Min-SE Duration: 1800 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/Session-Timer/sipSTSLInitialSRReqPeerEventGen : sending received session expires to the peer leg Nov 24 17:01:24.486: //63/842E0F800002/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_PASS_ST_PARAMS, SE Value:7200, SE Refresher:none, Min-SE Value:1800, flags:2001 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/Session-Timer/sipSTSLMain: SE: 7200;refresher:none peer refresher:none, flags:2001, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:1800, Configured Min-SE:1800 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIProcessNotifyCallInfoHeader: Callinfo parsed - Destination url = , duration = 500 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 16420 SIP: (63) Attribute mid, level 1 instance 1 not found. Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Nov 24 17:01:24.486: //-1/xxxxxxxxxxxx/SIP/Info/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 ext.ext.ext.ext for SIP Nov 24 17:01:24.486: //63/842E0F800002/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = ext.ext.ext.ext Nov 24 17:01:24.486: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec No Codec Nov 24 17:01:24.486: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96 Nov 24 17:01:24.486: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved as its in use by other codec No Codec Nov 24 17:01:24.486: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is reserved by another application Nov 24 17:01:24.486: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 Nov 24 17:01:24.486: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101 Nov 24 17:01:24.486: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec: Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711alaw) Negotiation Successful on Static Payload for m-line 1 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIDoPtimeNegotiation: No ptime present or multiple ptime attributes that can't be handled Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIDoDTMFRelayNegotiation: Requested DTMF-RELAY option(s) not found in Preferred DTMF-RELAY option list! Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIStreamTypeAndDtmfRelay: DTMF Relay mode: Inband Voice Nov 24 17:01:24.486: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1 payload_type=8, codec_bytes=160, codec=g711alaw, dtmf_relay=inband-voice stream_type=voice-only (0), dest_ip_address=10.0.0.2, dest_port=16420 Nov 24 17:01:24.486: //63/842E0F800002/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING) Nov 24 17:01:24.486: //63/842E0F800002/SIP/Media/sipSPIUpdCallWithSdpInfo: Preferred Codec : g711alaw, bytes :160 Preferred DTMF relay : h245-signal Preferred NTE payload : 98 Early Media : No Delayed Media : No Bridge Done : No New Media : No DSP DNLD Reqd : No Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Nov 24 17:01:24.486: //63/842E0F800002/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = ext.ext.ext.ext Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/ccsip_offer_ans_handle_rcvd_sdp: Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/ccsip_offer_ans_process_event: Nov 24 17:01:24.486: //63/842E0F800002/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_IDLE, event:E_SIP_INVITE_SDP_RCVD Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/ccsip_offer_ans_is_invite_offer_valid: - 1 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/ccsip_offer_ans_common_offer_rcvd_hdlr: Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/ccsip_iwf_handle_network_event: Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/ccsip_iwf_process_event: Nov 24 17:01:24.486: //63/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_RCVD_SDP Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sip_iwf_def_ed_rcvd_sdp_hdlr: Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: CallID 63, sdp 0x32E4D8BC channels 0x328E5CE4 Nov 24 17:01:24.486: //63/842E0F800002/SIP/Info/copy_channels: callId 63 size 0 ptr 0x31BD5E38) Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_copy_and_init_channelInfo_params: CCB t38 version 0 ipip_caps version 0 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_copy_and_init_channelInfo_params: CCB fax rate 2 ipip_caps rate 14400 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: stream_callid = 63, peer_stream_callid = -1 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Hndl ptype 0 mline 1 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Selecting codec g711ulaw Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/codec_found: Codec to be matched: 5 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/codec_found: No match for the codecs found.. Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Hndl ptype 8 mline 1 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Selecting codec g711alaw Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/codec_found: Codec to be matched: 6 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/codec_found: codecs[i] = 6 & codec = 6 are same.. Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 6 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_update_codec_params_in_channelInfo: Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_update_codec_params_in_channelInfo: Parsing from stream media address Nov 24 17:01:24.490: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_update_codec_params_in_channelInfo: Adding negotiated codec 6 ptype 8 time 20, bytes 160 as channel 0 mline 1 ss 1 10.0.0.2:16420 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Error/sipSPI_ipip_update_codec_params_in_channelInfo: failed to update call entry Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=0,stream->negotiated_codec_bytes=160,stream->mline_index=1, media_ndx=1 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIBwCacCalcAudioBandwidth: calculated audio bandwidth : codec g711alaw bw 64000 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Hndl ptype 18 mline 1 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Media/sipSPISelectCodecVersion: Codec (g729br8) is not in preferred list Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_update_static_codec_params: An exact codec match not configured, using interoperable codec g729r8 pre-ietf Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Selecting codec g729r8 pre-ietf Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/codec_found: Codec to be matched: 0 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/codec_found: No match for the codecs found.. Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Hndl ptype 101 mline 1 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_update_dynamic_codec_params: Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_upd_2833_dtmf_params: Nov 24 17:01:24.490: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Error/sipSPI_ipip_update_call_entry: failed to update call entry Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[0].codec = 6 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[1].codec = -1 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: srcChannelID = -1, dstChannelID = 63 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Media/sipSPIDisplayStreamInfo: Stream type : voice-only Media line : 1 State : STREAM_ADDING (2) Stream address type : 1 Callid : 63 Peer Callid : -1 RTP/SRTP Negotiated : 8 Negotiated Codec : g711alaw, bytes :160 Nego. Codec payload : 8 (tx), 8 (rx) Negotiated DTMF relay : inband-voice Negotiated NTE payload : 0 (tx), 0 (rx) Negotiated CN payload : 0 Media Srce Addr/Port : [ext.ext.ext.ext]:0 Media Dest Addr/Port : [10.0.0.2]:16420 Nov 24 17:01:24.490: //63/842E0F8000 02/SIP/Info/sipSPI_ipip_calculate_channel_count: Number of streams to report = 1 Nov 24 17:01:24.490: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_ipip_set_channel_count: Unable to set CHANNEL_COUNT for callid 63 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Error/sip_iwf_sip_copy_sdp_to_channelInfo: Channel count is not set at this point. Not SIP-SIP or SET_MODE is not done. Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: sdp->chnl audio bw 80000 bps video bw 0 bps fax bw 0 bps Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sip_iwf_def_ed_rcvd_sdp_hdlr: Setting media_direction to 0 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIBwCacUpdateAccountedBw: bwcac update accounted BW Option 0 flow mode flow-through audio bw 80000 bps video bw 0 bps fax bw 0 bps total bw 80000 bps accounted bw 0 bps Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIBwCacUpdateInterfaceBw: bwcac acquiring interface GigabitEthernet0/1 bw 80 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIBwCacUpdateAccountedBw: bwcac update accounted bw (initial offer) accounted bw set to 80000 Nov 24 17:01:24.490: //63/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:S_SIP_IWF_SDP_RCVD_AWAIT_PEER_EVENT Nov 24 17:01:24.490: //63/842E0F800002/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_EARLY_DIALOG_OFFER_RCVD Nov 24 17:01:24.490: //63/842E0F800002/SIP/Media/sipSPIUpdCallWithSdpInfo: Stream type : voice-only Media line : 1 State : STREAM_ADDING (2) Stream address type : 1 Callid : 63 Negotiated Codec : g711alaw, bytes :160 Nego. Codec payload : 8 (tx), 8 (rx) Negotiated DTMF relay : inband-voice Negotiated NTE payload : 0 (tx), 0 (rx) Negotiated CN payload : 0 Media Srce Addr/Port : [ext.ext.ext.ext]:0 Media Dest Addr/Port : [10.0.0.2]:16420 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIHandleInviteMedia: Negotiated Codec : g711alaw, bytes :160 Preferred Codec : g711alaw, bytes :160 Preferred DTMF relay 1 : 2 Preferred DTMF relay 2 : 0 Negotiated DTMF relay : 0 Preferred and Negotiated NTE payloads: 98 0 Preferred and Negotiated NSE payloads: 100 0 Preferred and Negotiated Modem Relay: 0 0 Preferred and Negotiated V150.1 Modem Passthrough: 0 0 Preferred and Negotiated V150.1 Modem Relay: 0 0 Preferred and Negotiated Modem Relay GwXid: 1 0 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIBwCacIsDialPeerBwAvailable: bwcac NOP dial-peer bw available tag 9011 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIBwCacIsInterfaceBwAvailable: bwcac interface bw threshold not configured Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIBwCacVerifyBwThreshold: bwcac verify bw threshold, bw available allow call total bw 80000 bps Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active Nov 24 17:01:24.490: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 16422 for stream 1 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=16422 Nov 24 17:01:24.490: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 16422 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIUpdateSrcSdpVariablePart: SIP update src sdp, negoitated codec 6, payload type 8 Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = 842e0f80-47316464-31346-3402000a@10.0.2.52 Nov 24 17:01:24.490: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/ccsip_api_call_setup_ind: Headers from INVITE added to callInfo container Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:2 tag:0 Nov 24 17:01:24.490: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Date Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.490: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Call-Info Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.490: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Allow Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.490: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header From Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.490: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Allow-Events Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.490: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header P-Asserted-Identity Nov 24 17:01:24.490: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Supported Nov 24 17:01:24.494: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Min-SE Nov 24 17:01:24.494: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Cisco-Guid Nov 24 17:01:24.494: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Remote-Party-ID Nov 24 17:01:24.494: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Content-Length Nov 24 17:01:24.494: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header User-Agent Nov 24 17:01:24.494: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header To Nov 24 17:01:24.494: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Contact Nov 24 17:01:24.494: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Expires Nov 24 17:01:24.494: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Content-Type Nov 24 17:01:24.494: //63/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:24.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Call-ID194.85.94 t=0 0 m=audio 16424 RTP/AVP 8 100 101 c=IN IP4 ext.ext.ext.ext a=rtpmap:8 PCMA/8000 a=rtpmap:100 X-NSE/8000 a=fmtp:100 192-194 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 Nov 24 17:01:25.646: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [217.20.39.101]:5060, local_address:[ext.ext.ext.ext] Nov 24 17:01:25.646: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Nov 24 17:01:25.646: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x31C7E00C Nov 24 17:01:25.646: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x31C7E00C, addr=217.20.39.101, port=5060, local_addr=ext.ext.ext.ext, connid=6, transport=UDP Nov 24 17:01:25.646: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 connId 6 Nov 24 17:01:25.646: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Nov 24 17:01:25.646: //64/842E0F800002/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP ext.ext.ext.ext:5060;received=ext.ext.ext.ext;rport=54689;branch=z9hG4bKFBF1 From: "OrbTalk 0100" ;tag=12A6C8-226 To: ;tag=1053ce00ee7f576c7d81feba4dc61aca.ed65 Call-ID: 5B498A64-733211E4-805A8E78-B6AD319D@ext.ext.ext.ext CSeq: 101 INVITE Proxy-Authenticate: Digest realm="sip.orbtalk.co.uk", nonce="547365917f9b160f5ece82d1592ab65a88901ace" Server: OrbTalk Content-Length: 0 Nov 24 17:01:25.646: //64/842E0F800002/SIP/Info/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX Nov 24 17:01:25.646: //64/842E0F800002/SIP/Info/sipSPIP resendProcessing: Presend Processing called for 1 event Nov 24 17:01:25.646: //64/842E0F800002/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Nov 24 17:01:25.646: //64/842E0F800002/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Nov 24 17:01:25.646: //64/842E0F800002/SIP/Info/ccsip_offer_ans_handle_call_active: Nov 24 17:01:25.646: //64/842E0F800002/SIP/Info/ccsip_offer_ans_process_event: Nov 24 17:01:25.646: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_OFFER_SENT, event:E_SIP_DIALOG_ESTD Nov 24 17:01:25.646: //64/842E0F800002/SIP/Info/ccsip_offer_ans_process_event: O/A - cnfsm ret 2 Nov 24 17:01:25.646: //64/842E0F800002/SIP/Info/sipSPISendAck: Associated container=0x32B03D54 to Ack Nov 24 17:01:25.650: //64/842E0F800002/SIP/Transport/sipSPISendAck: Sending ACK to the transport layer Nov 24 17:01:25.650: //64/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:01:25.650: //64/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x32ED32CC, addr=217.20.39.101, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x0 Nov 24 17:01:25.650: //64/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:25.650: //64/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:25.650: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:217.20.39.101, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:25.650: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328F04B8 is already on connection=0x3223A93C context_list Nov 24 17:01:25.650: //64/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x32ED32CC Nov 24 17:01:25.650: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x32ED32CC, addr=217.20.39.101, port=5060, local_addr=ext.ext.ext.ext, connId=6 for UDP Nov 24 17:01:25.650: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/sipSPIGenerateAuthorizationResponse: HA1 is: 9f2a16d441b18b0e86b76d124905893e Nov 24 17:01:25.650: //64/842E0F800002/SIP/State/sipSPIChangeState: 0x328F04B8 : State change from (STATE_SENT_INVITE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) Nov 24 17:01:25.650: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone ASD to SIP default timezone = GMT Nov 24 17:01:25.650: //64/842E0F800002/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ Nov 24 17:01:25.650: //64/842E0F800002/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:0, container:32B0361C Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ Nov 24 17:01:25.650: //64/842E0F800002/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_PASS_ST_PARAMS, SE Value:7200, SE Refresher:none, Min-SE Value:1800, flags:2001 Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/Session-Timer/sipSTSLSRReqPassPeerEventHndlr: session timer negotiated end to end Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/Session-Timer/sipSTSLMain: SE: 7200;refresher:none peer refresher:none, flags:2120, posted event:E_STSL_PASS_ST_PARAMS, reason:4 Configured SE:1800, Configured Min-SE:1800 Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 0 event Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/ccsip_offer_ans_handle_sent_sdp: Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/ccsip_offer_ans_process_event: Nov 24 17:01:25.650: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_OFFER_SENT, event:E_SIP_INVITE_SDP_SENT Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/ccsip_offer_ans_process_event: O/A - cnfsm ret 2 Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not an Forked leg.. Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added. SIP: (64) Group (a= group line) attribute, level 65535 instance 1 not found. Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/sipSPISendInvite: Associated container=0x32B0361C to Invite Nov 24 17:01:25.650: //64/842E0F800002/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer Nov 24 17:01:25.650: //64/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:01:25.650: //64/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x30033934, addr=217.20.39.101, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x255E8CF4 Nov 24 17:01:25.650: //-1/xxxxxxxxxxxx/SIP/Info/sip_profiles_application_modify_remove_header: Header before modification : From: "OrbTalk 0100" ;tag=12A6C8-226 Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/sip_profiles_check_and_get_variables_in_replace_pattern: substituted_replace_pattern : Nov 24 17:01:25.650: //-1/xxxxxxxxxxxx/SIP/Info/sip_profiles_application_modify_remove_header: Header after modification : From: "OrbTalk 0100" ;tag=12A6C8-226 Nov 24 17:01:25.650: //64/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:25.650: //64/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:25.650: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:217.20.39.101, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:25.650: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328F04B8 is already on connection=0x3223A93C context_list Nov 24 17:01:25.650: //64/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x30033934 Nov 24 17:01:25.650: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x30033934, addr=217.20.39.101, port=5060, local_addr=ext.ext.ext.ext, connId=6 for UDP Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/sentInviteRequest: Sent Invite in state STATE_IDLE Nov 24 17:01:25.650: //-1/xxxxxxxxxxxx/SIP/Info/sentInviteRequest: Transaction active. Facilities will be queued. Nov 24 17:01:25.650: //64/842E0F800002/SIP/State/sipSPIChangeState: 0x328F04B8 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_SENT_INVITE, SUBSTATE_NONE) Nov 24 17:01:25.650: //64/842E0F800002/SIP/Media/sipSPIProcessRtpSessions: Processing stream state = STREAM_ADDING Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/sipSPIAddStream: set stream_callid from ccb->ccCallID:0x40, media_type:0 Nov 24 17:01:25.650: //64/842E0F800002/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 64) to the VOIP RTP library Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Nov 24 17:01:25.650: //64/842E0F800002/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = ext.ext.ext.ext Nov 24 17:01:25.650: //64/842E0F800002/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1 Nov 24 17:01:25.650: //64/842E0F800002/SIP/Info/sipSPIUpdateRtcpSession: ccb->flags != LOOPBACK Nov 24 17:01:25.650: //64/842E0F800002/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info laddr = ext.ext.ext.ext, lport = 16424, raddr = 0.0.0.0, rport=0, do_rtcp=FALSE src_callid = 64, dest_callid = -1, stream type = voice+dtmf, stream direction = RECVONLY media_ip_addr = - , vrf tableid = 0 media_addr_type = 1 negotiated_bandwidth (kbps) = 0 Nov 24 17:01:25.650: //64/842E0F800002/SIP/Media/sipSPIUpdateRtcpSession: RTP session already created - update Nov 24 17:01:25.954: //64/842E0F800002/SIP/State/sipSPIChangeState: 0x328F04B8 : State change from (STATE_SENT_INVITE, SUBSTATE_NONE) to (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) Nov 24 17:01:29.990: %IP-4-DUPADDR: Duplicate address ext.ext.ext.ext on GigabitEthernet0/1, sourced by 00a0.8e7d.a74b Nov 24 17:01:30.690: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [217.20.39.101]:5060, local_address:[ext.ext.ext.ext] Nov 24 17:01:30.690: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Nov 24 17:01:30.690: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x31C7E00C Nov 24 17:01:30.690: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x31C7E00C, addr=217.20.39.101, port=5060, local_addr=ext.ext.ext.ext, connid=6, transport=UDP Nov 24 17:01:30.690: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 connId 6 Nov 24 17:01:30.690: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Nov 24 17:01:30.690: //64/842E0F800002/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK10987 From: "OrbTalk 0100" ;tag=12A6C8-226 To: ;tag=1901410832 Call-ID: 5B498A64-733211E4-805A8E78-B6AD319D@ext.ext.ext.ext CSeq: 102 INVITE Timestamp: 1416848485 Contact: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE Content-Type: application/sdp Content-Length: 453 v=0 o=- 149053058 0 IN IP4 217.20.39.102 s=Cisco SDP 0 c=IN IP4 217.20.39.102 t=0 0 m=audio 59300 RTP/AVP 8 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sqn:0 a=cdsc: 1 audio RTP/AVP 8 101 a=cdsc: 3 image udptl t38 a=cpar: a=T38FaxVersion:0 a=cpar: a=T38FaxRateManagement:transferredTCF a=cpar: a=T38FaxMaxDatagram:160 a=cpar: a=T38FaxUdpEC:t38UDPRedundancy a=X-sqn:0 a=X-cap: 1 image udptl t38 a=nortpproxy:yes Nov 24 17:01:30.690: //64/842E0F800002/SIP/Info/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX Nov 24 17:01:30.690: //64/842E0F800002/SIP/Info/ccsip_api_update_allowed: UPDATE(1) allowed Nov 24 17:01:30.690: //64/842E0F800002/SIP/Info/ccsip_offer_ans_handle_update_allowed: Nov 24 17:01:30.690: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container SIP: Warning: Unrecognized attribute (nortpproxy) Nov 24 17:01:30.690: //64/842E0F800002/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1 Nov 24 17:01:30.690: //64/842E0F800002/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 59300 SIP: Attribute mid, level 1 instance 1 not found. Nov 24 17:01:30.690: //64/842E0F800002/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Nov 24 17:01:30.694: //64/842E0F800002/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = ext.ext.ext.ext Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec No Codec Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96 Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved as its in use by other codec No Codec Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is reserved by another application Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101 Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec: Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711alaw) Negotiation Successful on Static Payload for m-line 1 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20 Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711alaw ptime :20, codecbytes: 160 Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711alaw Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1 Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the payload type 101 for RTP-NTE Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events. Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: X-cap count = 1 Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1 payload_type=8, codec_bytes=160, codec=g711alaw, dtmf_relay=rtp-nte stream_type=voice+dtmf (1), dest_ip_address=217.20.39.102, dest_port=59300 Nov 24 17:01:30.694: //64/842E0F800002/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING) Nov 24 17:01:30.694: //64/842E0F800002/SIP/Media/sipSPIReplaceSDP: Main stream got changed & it's Flow Around Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/ccsip_iwf_handle_generic_event: Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: Nov 24 17:01:30.694: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sip_early_dialog_container, cur_state:S_SIP_IWF_SDP_SENT_AWAIT_SDP, event:E_SIP_IWF_EV_CALL_BRIDGE Nov 24 17:01:30.694: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: IWF - cnfsm ret 2 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Media/sipSPIUpdCallWithSdpInfo: Preferred Codec : g711alaw, bytes :160 Preferred DTMF relay : rtp-nte Preferred NTE payload : 101 Early Media : No Delayed Media : No Bridge Done : No New Media : No DSP DNLD Reqd : No Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Nov 24 17:01:30.694: //64/842E0F800002/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = ext.ext.ext.ext Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/ccsip_offer_ans_handle_rcvd_sdp: Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/ccsip_offer_ans_process_event: Nov 24 17:01:30.694: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_OFFER_SENT, event:E_SIP_INVITE_RESP_SDP_RCVD Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/ccsip_offer_ans_is_incoming_invite_resp_answer_valid: - 1 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/ccsip_offer_ans_common_answer_rcvd_hdlr: Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/ccsip_iwf_handle_network_event: Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: Nov 24 17:01:30.694: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sip_early_dialog_container, cur_state:S_SIP_IWF_SDP_SENT_AWAIT_SDP, event:E_SIP_IWF_EV_RCVD_SDP Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/is_call_do_2_eo: Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/is_trigger_update_passthru_resp: Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/is_trigger_update_passthru_resp: Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/is_media_renegotiation_trigger_needed: Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sip_iwf_sip_ed_rcvd_sdp_hdlr: Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: CallID 64, sdp 0x32F067B0 channels 0x328F1C14 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/copy_channels: callId 64 size 240 ptr 0x32ED9F50) Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: stream_callid = 64, peer_stream_callid = -1 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Hndl ptype 8 mline 1 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Selecting codec g711alaw Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/codec_found: Codec to be matched: 6 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/codec_found: codecs[i] = 6 & codec = 6 are same.. Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 6 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPI_ipip_update_codec_params_in_channelInfo: Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPI_ipip_update_codec_params_in_channelInfo: Parsing from stream media address Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPI_ipip_update_codec_params_in_channelInfo: Adding negotiated codec 6 ptype 8 time 20, bytes 160 as channel 0 mline 1 ss 1 217.20.39.102:59300 Nov 24 17:01:30.694: //64/842E0F800002/SIP/I nfo/sipSPIUpdateCallEntry: Call 64 set InfoType to SPEECH Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=20,stream->negotiated_codec_bytes=160,stream->mline_index=1, media_ndx=1 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPIBwCacCalcAudioBandwidth: calculated audio bandwidth : codec g711alaw bw 64000 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Hndl ptype 101 mline 1 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPI_ipip_update_dynamic_codec_params: Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPI_ipip_upd_2833_dtmf_params: Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPI_ipip_upd_2833_dtmf_params: setting ipip_caps DTMF to RFC2833: callid = 64, dtmf = 6 Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPIUpdateCallEntry: Call 64 set InfoType to SPEECH Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[0].codec = 6 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[1].codec = -1 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: srcChannelID = -1, dstChannelID = 64 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Media/sipSPIDisplayStreamInfo: Stream type : voice+dtmf Media line : 1 State : STREAM_ADDING (2) Stream address type : 1 Callid : 64 Peer Callid : -1 RTP/SRTP Negotiated : 8 Negotiated Codec : g711alaw, bytes :160 Nego. Codec payload : 8 (tx), 8 (rx) Negotiated DTMF relay : rtp-nte Negotiated NTE payload : 101 (tx), 101 (rx) Negotiated CN payload : 0 Media Srce Addr/Port : [ext.ext.ext.ext]:16424 Media Dest Addr/Port : [217.20.39.102]:59300 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sipSPI_ipip_calculate_channel_count: Number of streams to report = 1 Nov 24 17:01:30.694: //-1/xxxxxxxxxxxx/SIP/Info/sipSPI_ipip_set_channel_count: Setting CHANNEL_COUNT = 1 for callid 64 Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: sdp->chnl audio bw 80000 bps video bw 0 bps fax bw 0 bps Nov 24 17:01:30.694: //64/842E0F800002/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 25 Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 9 Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_ipip_media_service_get_event_data: Mid-call=0 Nov 24 17:01:30.698: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IPIPMS:cur_container:ccsip_ipip_media_service_main_container, cur_state:S_IPIP_MEDIA_SERV_STATE_IDLE, event:E_IPIP_MEDIA_SERV_EV_ANS_RCVD Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_handle_generic_event: Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: IWF in use, deferring event Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_iwf_handle_peer_event: Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 3, Event Id: 28 Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_iwf_process_event: Nov 24 17:01:30.698: //63/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sip_early_dialog_container, cur_state:S_SIP_IWF_SDP_RCVD_AWAIT_PEER_EVENT, event:E_SIP_IWF_EV_PEER_CAPS Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sip_iwf_sip_process_caps_ind: destCallID=63, srcCallID=64, peer_ccb->call_info.currentLocalName=OrbTalk 0100, peer_ccb->call_info.currentRemoteName=, ccb->call_info.currentLocalName=, ccb->call_info.currentRemoteName= Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=63, current_seq_num=0x253E Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=63, current_seq_num=0x0 Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_update_stream_negotiated_codec: Codec that peer call leg has indicated is same what this call leg is already using.. Do nothing.. Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sip_iwf_sip_process_caps_ind: Load DSP with negotiated codec: g711alaw, Bytes=160 Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sip_iwf_sip_process_caps_ind: Set forking flag to 0x0 Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_INBAND_VOICE_AND_OOB Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0 Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=64 Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sip_set_modem_caps: Disabling Modem Relay... Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sip_set_modem_caps: nse payload = 0, ptru mode = 0, ptru-codec=2, redundancy=0, xid=0, relay=0, sprt-retry=12, latecncy=200, compres-dir=3, dict=1024, strnlen=32 Nov 24 17:01:30.698: //63/842E0F800002/SIP/Media/sipSPISetStreamInfo: 0 Active Streams Nov 24 17:01:30.698: //63/842E0F800002/SIP/Media/sipSPISetStreamInfo: Number of active streams is zero (0)! Nov 24 17:01:30.698: //63/842E0F800002/SIP/Media/sipSPISetStreamInfo: caps.stream_count=0,caps.stream[0].stream_type=0xFFFF, caps.stream_list.xmitFunc= Nov 24 17:01:30.698: //63/842E0F800002/SIP/Media/sipSPISetStreamInfo: ??unknown??, caps.stream_list.context= Nov 24 17:01:30.698: //63/842E0F800002/SIP/Media/sipSPISetStreamInfo: 0x0 (gccb) Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sip_iwf_sip_process_caps_ind: Load DSP with codec : g711alaw, Bytes=160, payload = 8 Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sip_iwf_sip_process_caps_ind: ccsip_caps_ind: ccb->pld.flags_ipip = 0x400003 Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sip_iwf_sip_process_caps_ind: No video caps detected in the caps posted by peer leg Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sip_iwf_sip_process_caps_ind: Calling cc_api_caps_ack() Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_handle_peer_event: Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 3, Event Id: 29 Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: IWF in use, deferring event Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_handle_peer_event: Return value : SIP_IWF_SUCCESS Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_map_cc_return_code: Mapping SIP_IWF_SUCCESS Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 7 Nov 24 17:01:30.698: //63/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IPIPMS:cur_container:ccsip_ipip_media_service_main_container, cur_state:S_IPIP_MEDIA_SERV_STATE_IDLE, event:E_IPIP_MEDIA_SERV_EV_PEER_CAPS_IND Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_handle_peer_event: Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 3, Event Id: 29 Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: IWF in use, deferring event Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_handle_peer_event: Return value : SIP_IWF_SUCCESS Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_iwf_map_cc_return_code: Mapping SIP_IWF_SUCCESS Nov 24 17:01:30.698: //63/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_iwf_handle_peer_event: Return value : SIP_IWF_SUCCESS Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_iwf_map_cc_return_code: Mapping SIP_IWF_SUCCESS Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_offer_ans_notify_secondary_invite_resp: Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/copy_channels: callId 64 size 240 ptr 0x311D27EC) Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 178) Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_iwf_handle_peer_event: Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 1, Event Id: 178 Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sipSPI_ipip_read_channel_count: CHANNEL_COUNT in TD container of (64) = 1 Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/sipSPIGetMultiMediaTriggerData: media trigger for this event = 0. This is the last event for this sequence. Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_IWF Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_iwf_handle_peer_event: Return value : SIP_IWF_SUCCESS Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_iwf_map_cc_return_code: Mapping SIP_IWF_SUCCESS Nov 24 17:01:30.698: //63/842E0F800002/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/ccsip_update_srtp_caps: 2598: Not Sending NULL SRTP CAPS to SIP LEG Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPIBwCacUpdateAccountedBw: bwcac update accounted BW Option 1 flow mode flow-through audio bw 80000 bps video bw 0 bps fax bw 0 bps total bw 80000 bps accounted bw 80000 bps Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPIBwCacUpdateAccountedBw: bwcac update accounted bw (initial answer) no change in accounted bw 80000 Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPIBwCacUpdateInterfaceBw: NOP (no interface change) Nov 24 17:01:30.698: //64/842E0F8 00002/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:S_SIP_IWF_SDP_DONE Nov 24 17:01:30.698: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_EARLY_DIALOG_OFFER_ANSWER_COMPLETE Nov 24 17:01:30.698: //64/842E0F800002/SIP/Media/sipSPIUpdCallWithSdpInfo: Stream type : voice+dtmf Media line : 1 State : STREAM_ADDING (2) Stream address type : 1 Callid : 64 Negotiated Codec : g711alaw, bytes :160 Nego. Codec payload : 8 (tx), 8 (rx) Negotiated DTMF relay : rtp-nte Negotiated NTE payload : 101 (tx), 101 (rx) Negotiated CN payload : 0 Media Srce Addr/Port : [ext.ext.ext.ext]:16424 Media Dest Addr/Port : [217.20.39.102]:59300 Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPIBwCacIsDialPeerBwAvailable: bwcac NOP dial-peer bw available tag 9000 Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPIBwCacVerifyBwThreshold: bwcac verify bw threshold, bw available allow call total bw 80000 bps Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:2 tag:0 Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Allow Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header From Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Timestamp Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Content-Length Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header To Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Contact Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Content-Type Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Call-ID Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Via Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:30.698: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header CSeq Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:30.698: //64/842E0F800002/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled: - 1 Nov 24 17:01:30.702: //64/842E0F800002/SIP/Info/sipSPI_ipip_GetPassthruContent: Found Single Content in SIP Msg Nov 24 17:01:30.702: //-1/xxxxxxxxxxxx/SIP/Info/sipSPI_default_IsUnsupportedContentType: Content-Type application/sdp matched Nov 24 17:01:30.702: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: No content in SIP Msg or Error Nov 24 17:01:30.702: //63/842E0F800002/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 98) Nov 24 17:01:30.702: //63/842E0F800002/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED Nov 24 17:01:30.702: //64/842E0F800002/SIP/Info/HandleSIP1xxSessionProgress: ccsip_api_call_cut_progress returned: SIP_SUCCESS Nov 24 17:01:30.702: //64/842E0F800002/SIP/State/sipSPIChangeState: 0x328F04B8 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) to (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) Nov 24 17:01:30.702: //64/842E0F800002/SIP/Info/HandleSIP1xxSessionProgress: Transaction Complete. Lock on Facilities released. Nov 24 17:01:30.702: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 13 for event 69 Nov 24 17:01:30.702: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: Nov 24 17:01:30.702: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sip_early_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_UPDATE_STREAM_CONTEXT Nov 24 17:01:30.702: //64/842E0F800002/SIP/Info/sipSPI_ipip_update_stream_context: Exchange Audio Context for stream 64, media direction RECVONLY Nov 24 17:01:30.702: //63/842E0F800002/SIP/Info/ccsip_update_peer_caps: Stream is NULL Nov 24 17:01:30.702: //63/842E0F800002/SIP/Info/ccsip_update_peer_caps: gccb/stream is NULL, not updating now !! Nov 24 17:01:30.702: //64/842E0F800002/SIP/Info/sipSPIUpdateGccb: Failure from the peer leg so no updations now!! Nov 24 17:01:30.702: //64/842E0F800002/SIP/Info/sipSPIUpdateMediapolicy: media policy block doesnot exist Nov 24 17:01:30.702: //64/842E0F800002/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:311CF70C Nov 24 17:01:30.702: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Nov 24 17:01:30.702: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 13 for event 69 Nov 24 17:01:30.702: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: Nov 24 17:01:30.702: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sip_early_dialog _container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_PEER_CAPS_ACK, Nov 24 17:01:30.702: //64/842E0F800002/SIP/Info/sip_iwf_def_peer_caps_ack_hdlr: Nov 24 17:01:30.702: //64/842E0F800002/SIP/Info/sip_iwf_tdm_process_caps_ack: Set forking flag to 0x0 Nov 24 17:01:30.702: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Nov 24 17:01:30.702: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 13 for event 69 Nov 24 17:01:30.702: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: Nov 24 17:01:30.702: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sip_early_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_PEER_CAPS_ACK, Nov 24 17:01:30.702: //64/842E0F800002/SIP/Info/sip_iwf_def_peer_caps_ack_hdlr: Nov 24 17:01:30.702: //64/842E0F800002/SIP/Info/sip_iwf_tdm_process_caps_ack: Set forking flag to 0x0 Nov 24 17:01:30.702: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Nov 24 17:01:30.702: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 13 for event 69 Nov 24 17:01:30.702: //63/842E0F800002/SIP/Info/ccsip_iwf_process_event: 7777123456@ext.ext.ext.ext>;party=called;screen=yes;privacy=off Contact: Supported: sdp-anat Server: Cisco-SIPGateway/IOS-15.2.3.T1 Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 191 v=0 o=CiscoSystemsSIP-GW-UserAgent 4545 6737 IN IP4 ext.ext.ext.ext s=SIP Call c=IN IP4 ext.ext.ext.ext t=0 0 m=audio 16422 RTP/AVP 8 c=IN IP4 ext.ext.ext.ext a=rtpmap:8 PCMA/8000 a=ptime:20 Nov 24 17:01:34.682: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [217.20.39.101]:5060, local_address:[ext.ext.ext.ext] Nov 24 17:01:34.682: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Nov 24 17:01:34.682: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x31C7E00C Nov 24 17:01:34.682: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x31C7E00C, addr=217.20.39.101, port=5060, local_addr=ext.ext.ext.ext, connid=6, transport=UDP Nov 24 17:01:34.682: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 connId 6 Nov 24 17:01:34.682: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Nov 24 17:01:34.682: //64/842E0F800002/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 200 OK Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK10987 From: "OrbTalk 0100" ;tag=12A6C8-226 To: ;tag=1901410832 Call-ID: 5B498A64-733211E4-805A8E78-B6AD319D@ext.ext.ext.ext CSeq: 102 INVITE Timestamp: 1416848485 Contact: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE Require: timer Supported: timer Session-Expires: 7200;refresher=uac Content-Type: application/sdp Content-Length: 453 v=0 o=- 149053058 0 IN IP4 217.20.39.102 s=Cisco SDP 0 c=IN IP4 217.20.39.102 t=0 0 m=audio 59300 RTP/AVP 8 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sqn:0 a=cdsc: 1 audio RTP/AVP 8 101 a=cdsc: 3 image udptl t38 a=cpar: a=T38FaxVersion:0 a=cpar: a=T38FaxRateManagement:transferredTCF a=cpar: a=T38FaxMaxDatagram:160 a=cpar: a=T38FaxUdpEC:t38UDPRedundancy a=X-sqn:0 a=X-cap: 1 image udptl t38 a=nortpproxy:yes Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPIhandle200OKInvite: Transaction active. Facilities will be queued. Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPIhandle200OKInvite: *** This ccb is the parent Nov 24 17:01:34.686: //63/842E0F800002/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: 63/64, new src/dest ccCallids: 63/64 Nov 24 17:01:34.686: //63/842E0F800002/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=63, new streamcallid=63 Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/ccsip_iwf_handle_generic_event: Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: Nov 24 17:01:34.686: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sip_early_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_CALL_BRIDGE Nov 24 17:01:34.686: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: IWF - cnfsm ret 2 SIP: Warning: Unrecognized attribute (nortpproxy) Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPIProcessNotifyCallInfoHeader: Call-Info header with for Unsolicited Notify Absent,Disabling Unsolicited Notifies Nov 24 17:01:34.686: //64/842E0F800002/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP Nov 24 17:01:34.686: //64/842E0F800002/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:200, container:32B041CC Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr: Session-Expires value: 7200 refresher: uac Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_RESP Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/Session-Timer/sipSTSLInitialSRRespWithSEPeerEventGen: Session refresh and expiry has to be started by the endpoints Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/Session-Timer/sipSTSLProcessPassPeerEvent: session timer negotiated end to end Nov 24 17:01:34.686: //64/842E0F800002/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_PASS_ST_PARAMS, SE Value:7200, SE Refresher:uac, Min-SE Value:1800, flags:121 Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/Session-Timer/sipSTSLMain: SE: 7200;refresher:uac peer refresher:uac, flags:121, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:1800, Configured Min-SE:1800 Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:2 tag:0 Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Allow Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header From Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Supported Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport : Found Supported header Timestamp Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Content-Length Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Require Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header To Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Contact Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Content-Type Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Call-ID Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Via Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header CSeq Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckHeaderSupport: Found Supported header Session-Expires Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Header is not in hdr-list and not an unsupported Hdr as well Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled: - 1 Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_GetPassthruContent: Found Single Content in SIP Msg Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPI_default_IsUnsupportedContentType: Content-Type application/sdp matched Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: No content in SIP Msg or Error Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1 Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 59300 SIP: Attribute mid, level 1 instance 1 not found. Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Nov 24 17:01:34.686: //64/842E0F800002/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Nov 24 17:01:34.686: //64/842E0F800002/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = ext.ext.ext.ext Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved as its in use by other codec No Codec Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is reserved by another application Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96 Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101 Nov 24 17:01:34.686: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 96 for Codec: Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved as its in use by other codec No Codec Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is reserved by another application Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101 Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec: Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711alaw) Negotiation Successful on Static Payload for m-line 1 Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20 Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711alaw ptime :20, codecbytes: 160 Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20 Nov 24 17:01:34.690: //64/842E0F800002/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711alaw Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0 Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1 Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96 Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the payload type 101 for RTP-NTE Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events. Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: X-cap count = 1 Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0 Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0 Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1 payload_type=8, codec_bytes=160, codec=g711alaw, dtmf_relay=rtp-nte stream_type=voice+dtmf (1), dest_ip_address=217.20.39.102, dest_port=59300 Nov 24 17:01:34.690: //64/842E0F800002/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING) Nov 24 17:01:34.690: //64/842E0F800002/SIP/Media/sipSPICompareStreams: stream 1 dest_port: old=59300 new=59300 Nov 24 17:01:34.690: //64/842E0F800002/SIP/Media/sipSPIGetNewLocalMediaDirection: New Remote Media Direction = SENDRECV Present Local Media Direction = SENDRECV New Local Media Direction = SENDRECV retVal = 0 Nov 24 17:01:34.690: //64/842E0F800002/SIP/Media/sipSPICompareStreams: Flags set for stream 1: RTP_CHANGE=No CAPS_CHANGE=No RSVP_ADDR_CHANGE=No RSVP_MEDIA_CHANGE=No Nov 24 17:01:34.690: //64/842E0F800002/SIP/Media/sipSPICompareSDP: Flags set for call: NEW_MEDIA=No DSPDNLD_REQD=No IPIP_MEDIA=No Nov 24 17:01:34.690: //64/842E0F800002/SIP/Media/sipSPIReplaceSDP: Main stream got changed & it's Flow Around Nov 24 17:01:34.690: //64/842E0F800002/SIP/Media/sipSPIUpdCallWithSdpInfo: Preferred Codec : g711alaw, bytes :160 Preferred DTMF relay : rtp-nte Preferred NTE payload : 101 Early Media : No Delayed Media : No Bridge Done : Yes New Media : No DSP DNLD Reqd : No Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Nov 24 17:01:34.690: //64/842E0F800002/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = ext.ext.ext.ext Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/ccsip_offer_ans_handle_rcvd_sdp: Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/ccsip_offer_ans_process_event: Nov 24 17:01:34.690: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_OFFER_ANSWER_COMPLETE, event:E_SIP_INVITE_RESP_SDP_RCVD Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/ccsip_offer_ans_is_invite_resp_forked_and_eo: Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/ccsip_offer_ans_is_invite_resp_forked_and_do: Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/ccsip_offer_ans_is_invite_resp_ignored: Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/ccsip_offer_ans_ignore_hdlr: S_SIP_EARLY_DIALOG_OFFER_ANSWER_COMPLETE, E_SIP_INVITE_RESP_SDP_RCVD Nov 24 17:01:34.690: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: OA:next_state:CNFSM_NO_STATE_CHANGE Nov 24 17:01:34.690: //64/842E0F800002/SIP/Media/sipSP IUpdCallWithSdpInfo: Stream type : voice+dtmf Media line : 1 State : STREAM_ACTIVE (5) Stream address type : 1 Callid : 64 Negotiated Codec : g711alaw, bytes :160 Nego. Codec payload : 8 (tx), 8 (rx) Negotiated DTMF relay : rtp-nte Negotiated NTE payload : 101 (tx), 101 (rx) Negotiated CN payload : 0 Media Srce Addr/Port : [ext.ext.ext.ext]:16424 Media Dest Addr/Port : [217.20.39.102]:59300 Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIBwCacIsDialPeerBwAvailable: bwcac NOP dial-peer bw available tag 9000 Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIBwCacVerifyBwThreshold: bwcac verify bw threshold, bw available allow call total bw 0 bps Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIhandle200OKInvite: ccsip_api_call_connect_media returned: SIP_SUCCESS Nov 24 17:01:34.690: //64/842E0F800002/SIP/State/sipSPIChangeState: 0x328F04B8 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) to (STATE_RECD_PROCEEDING, SUBSTATE_NONE) Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIQoSRevertBW: Entry Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIShrlCall: Check peer: 9000 for Shared-Line call, callid: 64 Nov 24 17:01:34.690: //63/842E0F800002/SIP/Info/sipSPIShrlCall: Check peer: 9011 for Shared-Line call, callid: 63 Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIOptionsPing: Session Timer negotiated, not doing Options Ping Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled. Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIhandle200OKInvite: ccsip_api_call_connected returned: SIP_SUCCESS Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 1 event Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/ccsip_offer_ans_handle_call_active: Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/ccsip_offer_ans_process_event: Nov 24 17:01:34.690: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_OFFER_ANSWER_COMPLETE, event:E_SIP_DIALOG_ESTD Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/ccsip_offer_ans_dialog_established_hdlr: Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/ccsip_iwf_handle_generic_event: Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/ccsip_iwf_process_event: Nov 24 17:01:34.690: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sip_early_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_CALL_ACTIVE Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/is_call_do_2_eo: Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/is_call_set_for_delay_ack: Nov 24 17:01:34.690: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/is_mode_sip_sip: Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/ccsip_iwf_set_call_active: Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/ccsip_query_media_channel_info: Stream #:0, stream_call_id:64 Nov 24 17:01:34.690: //64/842E0F800002/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 10 Nov 24 17:01:34.690: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_GEN_SERVICE Nov 24 17:01:34.690: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_sip_mid_dialog_container Nov 24 17:01:34.690: //64/842E0F8 00002/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Nov 24 17:01:34.690: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_MID_DIALOG_IDLE Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/sipSPISendAck: Associated container=0x32B02E8C to Ack Nov 24 17:01:34.694: //64/842E0F800002/SIP/Transport/sipSPISendAck: Sending ACK to the transport layer Nov 24 17:01:34.694: //64/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:01:34.694: //64/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x32F0F9E4, addr=217.20.39.101, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x255EAD60 Nov 24 17:01:34.694: //64/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:34.694: //64/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:34.694: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:217.20.39.101, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:34.694: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328F04B8 is already on connection=0x3223A93C context_list Nov 24 17:01:34.694: //64/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x32F0F9E4 Nov 24 17:01:34.694: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x32F0F9E4, addr=217.20.39.101, port=5060, local_addr=ext.ext.ext.ext, connId=6 for UDP Nov 24 17:01:34.694: //64/842E0F800002/SIP/State/sipSPIChangeState: 0x328F04B8 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_NONE) to (STATE_ACTIVE, SUBSTATE_NONE) Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/ccsip_trigger_media_forking: MF: Not anchor leg. NO-OP. Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/ccsip_api_update_allowed: UPDATE(2) allowed Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/ccsip_offer_ans_handle_update_allowed: Nov 24 17:01:34.694: //64/842E0F800002/SIP/Call/sipSPICallInfo: The Call Setup Information is: Call Control Block (CCB) : 0x0x328F04B8 State of The Call : STATE_ACTIVE TCP Sockets Used : NO Calling Number : 441215550123 Called Number : 447777123456 Source IP Address (Sig ): ext.ext.ext.ext Destn SIP Req Addr:Port : 217.20.39.101:5060 Destn SIP Resp Addr:Port : 217.20.39.101:5060 Destination Name : sip.orbtalk.co.uk Nov 24 17:01:34.694: //64/842E0F800002/SIP/Call/sipSPIMediaCallInfo: Number of Media Streams: 1 Media Stream : 1 Negotiated Codec : g711alaw Negotiated Codec Bytes : 160 Nego. Codec payload : 8 (tx), 8 (rx) Negotiated Dtmf-relay : 6 Dtmf-relay Payload : 101 (tx), 101 (rx) Source IP Address (Media): ext.ext.ext.ext Source IP Port (Media): 16424 Destn IP Address (Media): 217.20.39.102 Destn IP Port (Media): 59300 Orig Destn IP Address:Port (Media): [ - ]:0 Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/sipSPICallActive: Transaction Complete. Lock on Facilities released. Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd Nov 24 17:01:34.694: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 14 for event 70 Nov 24 17:01:34.694: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IPIPMS:cur_container:ccsip_ipip_media_service_main_container, cur_state:S_IPIP_MEDIA_SERV_STATE_IDLE, event:E_IPIP_MEDIA_SERV_EV_CALL_ACTIVE Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/sipSPIRestoreCodecParams: Updating the preferred_codec_bytes.. Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/show_vcc_data: config_codec Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/show_vcc_data: Config_codec = 6 and codec bytes = 160 Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/show_vcc_data: xcoder_codec = -1 Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/show_vcc_data: channelInfo_codec Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/show_vcc_data: channelInfo_codec = 6 Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/show_vcc_data: preferred_codec Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/show_vcc_data: preferred_codec and codec bytes = 6 160 Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/show_vcc_data: OFFER_ALL, REINVITE_NEEDED, UNIVERSAL_XCODER = 0 0 0 Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/show_vcc_data: RE_ASSOCIATION_NEEDED = 0 Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/show_vcc_data: Low Density call.. Nov 24 17:01:34.694: //64/842E0F800002/SIP/Info/sipSPIRestoreCodecParams: srtp call = 0, srtp fallback = 0 Nov 24 17:01:34.694: //64/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IPIPMS:next_state:CNFSM_NO_STATE_CHANGE Nov 24 17:01:34.694: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_call_connect: CCSIP_CALL_CONNECT: ccb ptr 328E4588 Nov 24 17:01:34.694: //63/842E0F800002/SIP/Info/ccsip_iwf_handle_generic_event: Nov 24 17:01:34.694: //63/842E0F800002/SIP/Info/ccsip_iwf_process_event: Nov 24 17:01:34.694: //63/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sip_early_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_CALL_CONNECT Nov 24 17:01:34.694: //63/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Nov 24 17:01:34.694: //63/842E0F800002/SIP/Info/sip_iwf_common_call_connect_hdlr: Nov 24 17:01:34.694: //63/842E0F800002/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Nov 24 17:01:34.694: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_call_connect: CCSIP_CALL_CONNECT: app_diaplay_name[] app_display_num[447777123456] Nov 24 17:01:34.694: //63/842E0F800002/SIP/Info/ccsip_call_connect: CCSIP_CALL_CONNECT : KPML_CONFIGURED[FALSE] collect_digits[447777123456] calledNumber[447777123456] display_name[] display_num[447777123456] Nov 24 17:01:34.694: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_CONNECT Nov 24 17:01:34.694: //64/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: ACK sip:217.20.39.101;did=6f6.88941606 SIP/2.0 Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK113C From: "OrbTalk 0100" ;tag=12A6C8-226 To: ;tag=1901410832 Date: Mon, 24 Nov 2014 17:01:25 GMT Call-ID: 5B498A64-733211E4-805A8E78-B6AD319D@ext.ext.ext.ext Max-Forwards: 70 CSeq: 102 ACK Proxy-Authorization: Digest username="1111111",realm="sip.orbtalk.co.uk",uri="sip:447777123456@sip.orbtalk.co.uk:5060",response="04805726c859cebc7d75d64419877e34",nonce="547365917f9b160f5ece82d1592ab65a88901ace",algorithm=md5 Allow-Events: telephone-event Content-Length: 0 Nov 24 17:01:34.694: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 7 Nov 24 17:01:34.694: //63/842E0F800002/SIP/Info/sipAppMsgPlatformPreprocessor: delayed_media:FALSE, recvd msg->type == SIPSPI_EV_CC_CALL_CONNECT, invoke preprocessConnect Nov 24 17:01:34.694: //63/842E0F800002/SIP/Info/sipSPIAddCiscoGcid: Gcid value not set - not adding header. Nov 24 17:01:34.694: //63/842E0F800002/SIP/Info/sipSPI_ipip_set_history_info_header: No HI header recvd from container Nov 24 17:01:34.694: //63/842E0F800002/SIP/Info/sipSPIQoSRevertBW: Entry Nov 24 17:01:34.694: //63/842E0F800002/SIP/Info/preprocessConnect: Write sdp_info into msg_body Nov 24 17:01:34.694: //63/842E0F800002/SIP/Info/sipSPIBwCacIsDialPeerBwAvailable: bwcac NOP dial-peer bw available tag 9011 Nov 24 17:01:34.694: //63/842E0F800002/SIP/Info/sipSPIBwCacVerifyBwThreshold: bwcac verify bw threshold, bw available allow call total bw 0 bps Nov 24 17:01:34.698: //63/842E0F800002/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP Nov 24 17:01:34.698: //63/842E0F800002/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:200, container:32B036CC194.85.94>;party=called;screen=no;privacy=off Contact: Supported: replaces Supported: sdp-anat Server: Cisco-SIPGateway/IOS-15.2.3.T1 Session-Expires: 7200;refresher=uac Require: timer Supported: timer Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 191 v=0 o=CiscoSystemsSIP-GW-UserAgent 4545 6737 IN IP4 ext.ext.ext.ext s=SIP Call c=IN IP4 ext.ext.ext.ext t=0 0 m=audio 16422 RTP/AVP 8 c=IN IP4 ext.ext.ext.ext a=rtpmap:8 PCMA/8000 a=ptime:20 Nov 24 17:01:35.394: //63/842E0F800002/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off Nov 24 17:01:35.394: //63/842E0F800002/SIP/Info/sipSPIAppAddCallInfoUI: callinfo UI update request for callid: 63 Nov 24 17:01:35.394: //63/842E0F800002/SIP/Info/sipSPISendInviteResponse: Transaction active. Facilities will be queued. SIP: (63) Group (a= group line) attribute, level 65535 instance 1 not found. Nov 2 4 17:01:35.394: //63/842E0F800002/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp and dest_sdp available, should be a midcall request Nov 24 17:01:35.394: //63/842E0F800002/SIP/Info/sipSPISendInviteResponse: Associated container=0x32B036CC to Invite Response 200 Nov 24 17:01:35.394: //63/842E0F800002/SIP/Transport/sipSPISendInviteResponse: Sending 200OK Response to the Transport Layer Nov 24 17:01:35.394: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x32F0F9E4, addr=10.0.2.52, port=5060, sentBy_port=5060, local_addr=ext.ext.ext.ext, is_req=0, transport=1, switch=0, callBack=0x0 Nov 24 17:01:35.394: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:35.394: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:35.394: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x32F0F9E4 to default port=5060 Nov 24 17:01:35.394: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:35.394: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:01:35.394: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x32F0F9E4 Nov 24 17:01:35.394: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x32F0F9E4, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:01:35.394: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.2.52:5060;branch=z9hG4bK12768f77bfbaa8 From: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 To: ;tag=12BBF4-1D21 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 CSeq: 101 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Remote-Party-ID: ;party=called;screen=no;privacy=off Contact: Supported: replaces Supported: sdp-anat Server: Cisco-SIPGateway/IOS-15.2.3.T1 Session-Expires: 7200;refresher=uac Require: timer Supported: timer Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 191 v=0 o=CiscoSystemsSIP-GW-UserAgent 4545 6737 IN IP4 ext.ext.ext.ext s=SIP Call c=IN IP4 ext.ext.ext.ext t=0 0 m=audio 16422 RTP/AVP 8 c=IN IP4 ext.ext.ext.ext a=rtpmap:8 PCMA/8000 a=ptime:20 Nov 24 17:01:36.406: //63/842E0F800002/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off Nov 24 17:01:36.406: //63/842E0F800002/SIP/Info/sipSPIAppAddCallInfoUI: callinfo UI update request for callid: 63 Nov 24 17:01:36.406: //63/842E0F800002/SIP/Info/sipSPISendInviteResponse: Transaction active. Facilities will be queued. SIP: (63) Group (a= group line) attribute, level 65535 instance 1 not found. Nov 24 17:01:36.406: //63/842E0F800002/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp and dest_sdp available, should be a midcall request Nov 24 17:01:36.406: //63/842E0F800002/SIP/Info/sipSPISendInviteResponse: Associated container=0x32B036CC to Invite Response 200 Nov 24 17:01:36.406: //63/842E0F800002/SIP/Transport/sipSPISendInviteResponse: Sending 200OK Response to the Transport Layer Nov 24 17:01:36.406: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x32F0F9E4, addr=10.0.2.52, port=5060, sentBy_port=5060, local_addr=ext.ext.ext.ext, is_req=0, transport=1, switch=0, callBack=0x0 Nov 24 17:01:36.406: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:36.406: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:36.406: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x32F0F9E4 to default port=5060 Nov 24 17:01:36.410: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:36.410: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:01:36.410: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x32F0F9E4 Nov 24 17:01:36.410: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x32F0F9E4, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:01:36.410: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.2.52:5060;branch=z9hG4bK12768f77bfbaa8 From: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 To: ;tag=12BBF4-1D21 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 CSeq: 101 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGIS TER Allow-Events: telephone-event Remote-Party-ID: ;party=called;screen=no;privacy=off Contact: Supported: replaces Supported: sdp-anat Server: Cisco-SIPGateway/IOS-15.2.3.T1 Session-Expires: 7200;refresher=uac Require: timer Supported: timer Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 191 v=0 o=CiscoSystemsSIP-GW-UserAgent 4545 6737 IN IP4 ext.ext.ext.ext s=SIP Call c=IN IP4 ext.ext.ext.ext t=0 0 m=audio 16422 RTP/AVP 8 c=IN IP4 ext.ext.ext.ext a=rtpmap:8 PCMA/8000 a=ptime:20 Nov 24 17:01:38.198: //63/842E0F800002/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off Nov 24 17:01:38.198: //63/842E0F800002/SIP/Info/sipSPIAppAddCallInfoUI: callinfo UI update request for callid: 63 Nov 24 17:01:38.198: //63/842E0F800002/SIP/Info/sipSPISendInviteResponse: Transaction active. Facilities will be queued. SIP: (63) Group (a= group line) attribute, le vel 65535 instance 1 not found. Nov 24 17:01:38.198: //63/842E0F800002/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp and dest_sdp available, should be a midcall request Nov 24 17:01:38.198: //63/842E0F800002/SIP/Info/sipSPISendInviteResponse: Associated container=0x32B036CC to Invite Response 200 Nov 24 17:01:38.198: //63/842E0F800002/SIP/Transport/sipSPISendInviteResponse: Sending 200OK Response to the Transport Layer Nov 24 17:01:38.198: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x32F0F9E4, addr=10.0.2.52, port=5060, sentBy_port=5060, local_addr=ext.ext.ext.ext, is_req=0, transport=1, switch=0, callBack=0x0 Nov 24 17:01:38.198: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:38.198: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:38.198: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x32F0F9E4 to default port=5060 Nov 24 17:01:38.198: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:38.198: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:01:38.198: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x32F0F9E4 Nov 24 17:01:38.198: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x32F0F9E4, addr=10.0.2.52, port=5060, local_addr=80 .194.85.94, connId=5 for UDP Nov 24 17:01:38.198: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.2.52:5060;branch=z9hG4bK12768f77bfbaa8 From: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 To: ;tag=12BBF4-1D21 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 CSeq: 101 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Remote-Party-ID: ;party=called;screen=no;privacy=off Contact: Supported: replaces Supported: sdp-anat Server: Cisco-SIPGateway/IOS-15.2.3.T1 Session-Expires: 7200;refresher=uac Require: timer Supported: timer Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 191 v=0 o=CiscoSystemsSIP-GW-UserAgent 4545 6737 IN IP4 ext.ext.ext.ext s=SIP Call c=IN IP4 ext.ext.ext.ext t=0 0 m=audio 16422 RTP/AVP 8 c=IN IP4 ext.ext.ext.ext a=rtpmap:8 PCMA/8000 a=ptime:20 Nov 24 17:01:40.118: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [217.20.39.101]:5060, local_address:[ - ] Nov 24 17:01:40.118: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Nov 24 17:01:40.118: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x31C7E00C No tv 24 17:01:40.118: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x31C7E00C, addr=217.20.39.101, port=5060, local_addr=, connid=2, transport=UDP Nov 24 17:01:40.118: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 connId 2 Nov 24 17:01:40.118: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Received: OPTIONS sip:ext.ext.ext.ext:49721 SIP/2.0 Via: SIP/2.0/UDP 217.20.39.101:5060;branch=z9hG4bK6380652 From: sip:pinger@sip.orbtalk.co.uk;tag=6102de21 To: sip:ext.ext.ext.ext:49721 Call-ID: de8a5df3-61846205-6d2764@217.20.39.101 CSeq: 1 OPTIONS Max-Forwards: 70 Content-Length: 0 Nov 24 17:01:40.118: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Nov 24 17:01:40.118: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x328FC3E8) with key=[59] to table Nov 24 17:01:40.118: //-1/000000000000/SIP/Info/ccsip_offer_ans_init: Nov 24 17:01:40.118: //-1/000000000000/SIP/Info/ccsip_iwf_init: Nov 24 17:01:40.118: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init: Nov 24 17:01:40.118: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization: Entry... Nov 24 17:01:40.118: //-1/000000000000/SIP/Info/ccsip_ipip_media_forking_init: MF: Queue is initialised.. Nov 24 17:01:40.118: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 217.20.39.101,Port 5060, Transport 1, SentBy Port 5060 Nov 24 17:01:40.118: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop() Nov 24 17:01:40.118: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: ip_best_local_address ext.ext.ext.ext for SIP Nov 24 17:01:40.118: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr ext.ext.ext.ext Nov 24 17:01:40.118: //-1/6497BDB7805E/SIP/State/sipSPIChangeState: 0x328FC3E8 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) Nov 24 17:01:40.118: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 217.20.39.101,Port 5060, Transport 1, SentBy Por term not 5060 Nov 24 17:01:40.118: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone ASD to SIP default timezone = GMT Nov 24 17:01:40.122: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 217.20.39.101,Port 5060, Transport 1, SentBy Port 5060 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/ccsipInitPldCallingInfo: non-numeric calling number: pinger Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL Conversion failed for Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : pinger Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Error/sipSPIGetPeerByCalledPartyId: input arg error Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Error/sipSPIUpdateCallInfo: input argument error Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetCallConfig: Non dial peer leg - using RTP Supported Codecs Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 18 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 0 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 8 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 9 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 4 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 2 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 15 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 255 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Error/ccsip_ipip_media_forking_update_preferred_codec: MF: Not a Forked SIP leg.. Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIGetModemConfig: From Config: Modem NSE payload = 100, Passthrough = 4, Modem relay = 0, Gw-Xid = 1 SPRT latency 200, SPRT Retries = 12, Dict Size = 1024 String Len = 32, Compress dir = 3 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Error/ccsip_ipip_media_forking_anchor_leg_config: MF: Dial-peer is absent.. Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIMFChangeState: MF: Prev state = 0 & New state = -1 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/ccsip_ipip_media_forking_anchor_leg_reset: MF: Anchor leg config reset done... Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/populate_vcc_data: Non dial peer leg - using RTP Supported Codecs Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 18 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 0 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 8 Nov 24 17:01:40.122 : //68/6497BDB7805E/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 9 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 4 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 2 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 15 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 255 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:2 tag:0 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Error/sipSPI_ipip_build_consolidated_header_list: No headers associated with passthrulist tag: 0 and copylist tag: 0 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Nov 24 17:01:40.122: //-1/xxxxxxxxxxxx/SIP/Info/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 ext.ext.ext.ext for SIP Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = ext.ext.ext.ext Nov 24 17:01:40.122: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop() Nov 24 17:01:40.122: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: ip_best_local_address ext.ext.ext.ext for SIP Nov 24 17:01:40.122: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr ext.ext.ext.ext Nov 24 17:01:40.122: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_OPTIONS_RESP Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sact_idle_new_message_options: ccsip_api_options_ind returned: SIP_SUCCESS Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/State/sipSPIChangeState: 0x328FC3E8 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE) Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table. Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x328FC3E8 key=de8a5df3-61846205-6d2764@217.20.39.101 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 44 to table Nov 24 17:01:40.122: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 38 Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Info/sipSPISendOptionsResponse: Associated container=0x32B02BCC to Options Response Nov 24 17:01:40.122: //68/6497BDB7805E/SIP/Transport/sipSPITransportSendMessage: msg=0x32E8C97C, addr=217.20.39.101, port=5060, sentBy_port=5060, local_addr=, is_req=0, transport=1, switch=0, callBack=0x255EDCFC Nov 24 17:01:40.126: //68/6497BDB7805E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:40.126: //68/6497BDB7805E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:40.126: //68/6497BDB7805E/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x32E8C97C to default port=5060 Nov 24 17:01:40.126: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:217.20.39.101, rport:5060 with laddr: Nov 24 17:01:40.126: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x328FC3E8 with connection=0x317E6B84 context list Nov 24 17:01:40.126: //68/6497BDB7805E/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x32E8C97C Nov 24 17:01:40.126: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x32E8C97C, addr=217.20.39.101, port=5060, local_addr=, connId=2 for UDP Nov 24 17:01:40.126: //68/6497BDB7805E/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 200 OK Via: SIP/2.0/UDP 217.20.39.101:5060;branch=z9hG4bK6380652 From: sip:pinger@sip.orbtalk.co.uk;tag=6102de21 To: sip:ext.ext.ext.ext:49721;tag=12E0B8-22B4 Date: Mon, 24 Nov 2014 17:01:40 GMT Call-ID: de8a5df3-61846205-6d2764@217.20.39.101 Server: Cisco-SIPGateway/IOS-15.2.3.T1 CSeq: 1 OPTIONS Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Accept: application/sdp Supported: timer,resource-priority,replaces,sdp-anat Content-Type: application/sdp Content-Length: 167 v=0 o=CiscoSystemsSIP-GW-UserAgent 8603 9179 IN IP4 ext.ext.ext.ext s=SIP Call c=IN IP4 ext.ext.ext.ext t=0 0 m=audio 0 RTP/AVP 18 0 8 9 4 2 15 c=IN IP4 ext.ext.ext.ext Nov 24 17:01:42.094: //62/52B1D7698054/SIP/Info/sipSP IUdeleteccCallIdFromTable: Removing call id 3E Nov 24 17:01:42.094: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[56] removed. Nov 24 17:01:42.094: //62/52B1D7698054/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table. Nov 24 17:01:42.094: //62/52B1D7698054/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x328EA520 key=de8a5df3-10846205-8b2764@217.20.39.101 Nov 24 17:01:42.094: //62/52B1D7698054/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table. Nov 24 17:01:42.094: //62/52B1D7698054/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd Nov 24 17:01:42.094: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x31C7E00C, addr=217.20.39.101, port=5060, local_addr=, unregistering context=0x328EA520 Nov 24 17:01:42.094: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstancePurgeContextInConnection: Purging context gcb=0x328EA520 from the connection=0x317E6B84 context list Nov 24 17:01:42.094: //62/52B1D7698054/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed Nov 24 17:01:42.094: //62/52B1D7698054/SIP/Info/ccsip_offer_ans_delete: Nov 24 17:01:42.094: //62/52B1D7698054/SIP/Info/ccsip_iwf_delete: Nov 24 17:01:42.094: //62/52B1D7698054/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 0x328EA520 Nov 24 17:01:42.398: //63/842E0F800002/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off Nov 24 17:01:42.398: //63/842E0F800002/SIP/Info/sipSPIAppAddCallInfoUI: callinfo UI update request for callid: 63 Nov 24 17:01:42.398: //63/842E0F800002/SIP/Info/sipSPISendInviteResponse: Transaction active. Facilities will be queued. SIP: (63) Group (a= group line) attribute, level 65535 instance 1 not found. Nov 24 17:01:42.398: //63/842E0F800002/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp and dest_sdp available, should be a midcall request Nov 24 17:01:42.398: //63/842E0F800002/SIP/Info/sipSPISendInviteResponse: Associated container=0x32B036CC to Invite Response 200 Nov 24 17:01:42.398: //63/842E0F800002/SIP/Transport/sipSPISendInviteResponse: Sending 200OK Response to the Transport Layer Nov 24 17:01:42.398: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x32E88F3C, addr=10.0.2.52, port=5060, sentBy_port=5060, local_addr=ext.ext.ext.ext, is_req=0, transport=1, switch=0, callBack=0x0 Nov 24 17:01:42.398: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:42.398: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:42.398: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x32E88F3C to default port=5060 Nov 24 17:01:42.398: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:42.398: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:01:42.398: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x32E88F3C Nov 24 17:01:42.398: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x32E88F3C, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:01:42.398: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.2.52:5060;branch=z9hG4bK12768f77bfbaa8 From: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 To: ;tag=12BBF4-1D21 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 CSeq: 101 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Remote-Party-ID: ;party=called;screen=no;privacy=off Contact: Supported: replaces Supported: sdp-anat Server: Cisco-SIPGateway/IOS-15.2.3.T1 Session-Expires: 7200;refresher=uac Require: timer Supported: timer Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 191 v=0 o=CiscoSystemsSIP-GW-UserAgent 4545 6737 IN IP4 ext.ext.ext.ext s=SIP Call c=IN IP4 ext.ext.ext.ext t=0 0 m=audio 16422 RTP/AVP 8 c=IN IP4 ext.ext.ext.ext a=rtpmap:8 PCMA/8000 a=ptime:20 Nov 24 17:01:46.198: //63/842E0F800002/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off Nov 24 17:01:46.198: //63/842E0F800002/SIP/Info/sipSPIAppAddCallInfoUI: callinfo UI update request for callid: 63 Nov 24 17:01:46.198: //63/842E0F800002/SIP/Info/sipSPISendInviteResponse: Transaction active. Facilities will be queued. SIP: (63) Group (a= group line) attribute, level 65535 instance 1 not found. Nov 24 17:01:46.198: //63/842E0F800002/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp and dest_sdp available, should be a midcall request Nov 24 17:01:46.198: //63/842E0F800002/SIP/Info/sipSPISendInviteResponse: Associated container=0x32B036CC to Invite Response 2 00 Nov 24 17:01:46.198: //63/842E0F800002/SIP/Transport/sipSPISendInviteResponse: Sending 200OK Response to the Transport Layer Nov 24 17:01:46.198: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x2BE88DF0, addr=10.0.2.52, port=5060, sentBy_port=5060, local_addr=ext.ext.ext.ext, is_req=0, transport=1, switch=0, callBack=0x0 Nov 24 17:01:46.198: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:46.198: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:46.198: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x2BE88DF0 to default port=5060 Nov 24 17:01:46.198: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:46.198: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:01:46.198: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x2BE88DF0 Nov 24 17:01:46.198: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2BE88DF0, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:01:46.198: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.2.52:5060;branch=z9hG4bK12768f77bfbaa8 From: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 To: ;tag=12BBF4-1D21 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 CSeq: 101 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Remote-Party-ID: ;party=called;screen=no;privacy=off Contact: Supported: replaces Supported: sdp-anat Server: Cisco-SIPGateway/IOS-15.2.3.T1 Session-Expires: 7200;refresher=uac Require: timer Supported: timer Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 191 v=0 o=CiscoSystemsSIP-GW-UserAgent 4545 6737 IN IP4 ext.ext.ext.ext s=SIP Call c=IN IP4 ext.ext.ext.ext t=0 0 m=audio 16422 RTP/AVP 8 c=IN IP4 ext.ext.ext.ext a=rtpmap:8 PCMA/8000 a=ptime:20 Nov 24 17:01:48.790: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnAgeing: Holder=0x316E17F0 Connection=0x317E6B84, addr=217.20.39.101, port=5060, connid=2 has been REFRESHED Nov 24 17:01:48.790: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnAgeing: Holder=0x316E17F0 Connection=0x3223A93C, addr=217.20.39.101, port=5060, connid=6 has been REFRESHED Nov 24 17:01:48.790: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x316E17F0,addr=217.20.39.101 Nov 24 17:01:50.198: //63/842E0F800002/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off Nov 24 17:01:50.198: //63/842E0F800002/SIP/Info/sipSPIAppAddCallInfoUI: callinfo UI update request for callid: 63 Nov 24 17:01:50.198: //63/842E0F800002/SIP/Info/sipSPISendInviteResponse: Transaction active. Facilities will be queued. SIP: (63) Group (a= group line) attribute, level 65535 instance 1 not found. Nov 24 17:01:50.198: //63/842E0F800002/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp and dest_sdp available, should be a midcall request Nov 24 17:01:50.198: //63/842E0F800002/SIP/Info/sipSPISendInviteResponse: Associated container=0x32B036CC to Invite Response 200 Nov 24 17:01:50.198: //63/842E0F800002/SIP/Transport/sipSPISendInviteResponse: Sending 200OK Response to the Transport Layer Nov 24 17:01:50.198: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x32E88F3C, addr=10.0.2.52, port=5060, sentBy_port=5060, local_addr=ext.ext.ext.ext, is_req=0, transport=1, switch=0, callBack=0x0 Nov 24 17:01:50.198: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:50.198: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:50.198: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x32E88F3C to default port=5060 Nov 24 17:01:50.198: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:50.198: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:01:50.198: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x32E88F3C Nov 24 17:01:50.198: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x32E88F3C, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:01:50.198: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.2.52:5060;branch=z9hG4bK12768f77bfbaa8 From: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 To: ;tag=12BBF4-1D21 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 CSeq: 101 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Remote-Party-ID: ;party=called;screen=no;privacy=off Contact: Supported: replaces Supported: sdp-anat Server: Cisco-SIPGateway/IOS-15.2.3.T1 Session-Expires: 7200;refresher=uac Require: timer Supported: timer Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 191 v=0 o=CiscoSystemsSIP-GW-UserAgent 4545 6737 IN IP4 ext.ext.ext.ext s=SIP Call c=IN IP4 ext.ext.ext.ext t=0 0 m=audio 16422 RTP/AVP 8 c=IN IP4 ext.ext.ext.ext a=rtpmap:8 PCMA/8000 a=ptime:20 Nov 24 17:01:54.198: //63/842E0F800002/SIP/Error/act_sentsucc_wait_ack: Out of retries Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/ccsip_set_cc_cause_for_spi_err: Categorized cause:102, category:129 Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/ccsip_set_release_source_for_peer: ownCallId[63], src[6] Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/sipSPIInitiateDisconnect: Initiate call disconnect(102) for incoming call Nov 24 17:01:54.198: //-1/xxxxxxxxxxxx/SIP/Error/sipSPIGetContentQSIG: No Inbound Container Created !!! Nov 24 17:01:54.198: //-1/xxxxxxxxxxxx/SIP/Error/sipSPIGetContentQ931: No Inbound Container Created !!! Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 28 Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/ccsip_ipip_media_forking_post_event: MF: Not a Anchor SIP leg.. Nov 24 17:01:54.198: //63/842E0F800002/SIP/Error/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Invalid CCB/Data/Container Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/sipAddSipContainerToCallEntry: Unable to add passthru hdrs to container Nov 24 17:01:54.198: //-1/xxxxxxxxxxxx/SIP/Error/sipDestroyContainerContext: Corrupted/Freed Container=0x0 Nov 24 17:01:54.198: //63/842E0F800002/SIP/State/sipSPIChangeState: 0x328E4588 : State change from (STATE_SENT_SUCCESS, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE) Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 3 event Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/sipSPISendBye: Associated container=0x32B05824 to Bye Nov 24 17:01:54.198: //63/842E0F800002/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Nov 24 17:01:54.198: //63/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:01:54.198: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x2BE88DF0, addr=10.0.2.52, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x255EA2E4 Nov 24 17:01:54.198: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:54.198: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:54.198: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:54.198: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:01:54.198: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2BE88DF0 Nov 24 17:01:54.198: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2BE88DF0, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/sentByeDisconnecting: Sent Bye Request, starting DisconnectTimer Nov 24 17:01:54.198: //63/842E0F800002/SIP/State/sipSPIChangeState: 0x328E4588 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE) Nov 24 17:01:54.198: //64/842E0F800002/SIP/Info/updateGccbTxRxValues: No interworking required for stream type 1 Nov 24 17:01:54.198: //64/842E0F800002/SIP/Info/updateGccbTxRxValues: No interworking required for nte Nov 24 17:01:54.198: //64/842E0F800002/SIP/Info/updateGccbTxRxValues: No interworking required for nse Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/updateGccbTxRxValues: No interworking required for stream type 0 Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/updateGccbTxRxValues: No interworking required for nte Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/updateGccbTxRxValues: No interworking required for nse Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/sipSPIUpdateMediapolicy: media policy block doesnot exist Nov 24 17:01:54.198: //63/842E0F800002/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:31EDCFA0 Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/updateGccbTxRxValues: No interworking required for stream type 0 Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/updateGccbTxRxValues: No interworking required for nte Nov 24 17:01:54.198: //63/8 42E0F800002/SIP/Info/updateGccbTxRxValues: No interworking required for nse Nov 24 17:01:54.198: //64/842E0F800002/SIP/Info/updateGccbTxRxValues: No interworking required for stream type 1 Nov 24 17:01:54.198: //64/842E0F800002/SIP/Info/updateGccbTxRxValues: No interworking required for nte Nov 24 17:01:54.198: //64/842E0F800002/SIP/Info/updateGccbTxRxValues: No interworking required for nse Nov 24 17:01:54.198: //64/842E0F800002/SIP/Info/sipSPIUpdateMediapolicy: media policy block doesnot exist Nov 24 17:01:54.198: //64/842E0F800002/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:30037740 Nov 24 17:01:54.198: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:441215550123@10.0.2.52:5060 SIP/2.0 Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK121971 From: ;tag=12BBF4-1D21 To: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 User-Agent: Cisco-SIPGateway/IOS-15.2.3.T1 Max-Forwards: 70 Timestamp: 1416848514 CSeq: 101 BYE Reason: Q.850;cause=86 P-RTP-Stat: PS=1228,OS=196480,PR=341,OR=54560,PL=0,JI=0,LA=0,DU=19 Content-Length: 0 Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call. Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 28 Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service Nov 24 17:01:54.198: //63/842E0F800002/SIP/Info/ccsip_ipip_media_forking_post_event: MF: Not a Anchor SIP leg.. Nov 24 17:01:54.198: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT Nov 24 17:01:54.198: //64/842E0F800002/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call. Nov 24 17:01:54.198: //64/842E0F800002/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 28 Nov 24 17:01:54.198: //64/842E0F800002/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service Nov 24 17:01:54.198: //64/842E0F800002/SIP/Info/ccsip_ipip_media_forking_post_event: MF: Not a Anchor SIP leg.. Nov 24 17:01:54.198: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT Nov 24 17:01:54.198: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8 Nov 24 17:01:54.202: //63/842E0F800002/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SPI_EVENT Nov 24 17:01:54.202: //63/842E0F800002/SIP/Info/Session-Timer/sipSTSLMain: SE: 7200;refresher:uac peer refresher:uac, flags:121, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:1800, Configured Min-SE:1800 Nov 24 17:01:54.202: //63/842E0F800002/SIP/Info/sipSPIBwCacReleaseDialPeerBw: bwcac dial-peer bw 80 Kbps released for tag 9011 active bw 0 Kbps Nov 24 17:01:54.202: //63/842E0F800002/SIP/Info/sipSPIBwCacReleaseInterfaceBw: bwcac releasing interface GigabitEthernet0/1 bw 80 Kbps Nov 24 17:01:54.202: //63/842E0F800002/SIP/Info/sipSPIBwCacReleaseAccountedBw: bwcac released accounted bw 80000 bps Nov 24 17:01:54.202: //63/842E0F800002/SIP/Info/act_disconnecting_disconnect: Disconnect now.. no defer BYE.. Nov 24 17:01:54.202: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8 Nov 24 17:01:54.202: //64/842E0F800002/SIP/Info/sipSPIBwCacReleaseDialPeerBw: bwcac dial-peer bw 80 Kbps released for tag 9000 active bw 0 Kbps Nov 24 17:01:54.202: //64/842E0F800002/SIP/Info/sipSPIBwCacReleaseInterfaceBw: bwcac releasing interface GigabitEthernet0/1 bw 80 Kbps Nov 24 17:01:54.202: //64/842E0F800002/SIP/Info/sipSPIBwCacReleaseAccountedBw: bwcac released accounted bw 80000 bps Nov 24 17:01:54.202: //64/842E0F800002/SIP/Info/act_active_disconnect: act_active_disconnect: Disconnect now.. no defer BYE.. Nov 24 17:01:54.202: //64/842E0F800002/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Nov 24 17:01:54.202: //64/842E0F800002/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 3 event Nov 24 17:01:54.202: //64/842E0F800002/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Nov 24 17:01:54.202: //64/842E0F800002/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Nov 24 17:01:54.202: //64/842E0F800002/SIP/Info/sipSPIPushOrigRequestContainerIntoHolder: Request Container Holder is above threshold...trimming Nov 24 17:01:54.202: //64/842E0F800002/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Nov 24 17:01:54.202: //64/842E0F800002/SIP/Info/sipSPIGenerateAuthorizationResponse: HA1 is: 9f2a16d441b18b0e86b76d124905893e Nov 24 17:01:54.202: //64/842E0F800002/SIP/Info/sipSPISendBye: Associated container=0x32B0398C to Bye Nov 24 17:01:54.202: //64/842E0F800002/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Nov 24 17:01:54.202: //64/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:01:54.202: //64/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x2BE88 DF0, addr=217.20.39.101, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x255EA2E4 Nov 24 17:01:54.202: //64/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:54.202: //64/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:54.202: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:217.20.39.101, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:54.202: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328F04B8 is already on connection=0x3223A93C context_list Nov 24 17:01:54.202: //64/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2BE88DF0 Nov 24 17:01:54.202: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2BE88DF0, addr=217.20.39.101, port=5060, local_addr=ext.ext.ext.ext, connId=6 for UDP Nov 24 17:01:54.202: //64/842E0F800002/SIP/Info/sentByeDisconnecting: Sent Bye Request, starting DisconnectTimer Nov 24 17:01:54.202: //64/842E0F800002/SIP/State/sipSPIChangeState: 0x328F04B8 : State change from (STATE_ACTIVE, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE) Nov 24 17:01:54.202: //64/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:217.20.39.101;did=6f6.88941606 SIP/2.0 Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK131530 From: "OrbTalk 0100" ;tag=12A6C8-226 To: ;tag=1901410832 Date: Mon, 24 Nov 2014 17:01:25 GMT Call-ID: 5B498A64-733211E4-805A8E78-B6AD319D@ext.ext.ext.ext User-Agent: Cisco-SIPGateway/IOS-15.2.3.T1 Max-Forwards: 70 P-Asserted-Identity: "OrbTalk 0100" Timestamp: 1416848514 CSeq: 103 BYE Proxy-Authorization: Digest username="1111111",realm="sip.orbtalk.co.uk",uri="sip:217.20.39.101;did=6f6.88941606",response="7fd368e5c2912a6a05240bd85e319b58",nonce="547365917f9b160f5ece82d1592ab65a88901ace",algorithm=md5 Reason: Q.850;cause=102 P-RTP-Stat: PS=341,OS=54560,PR=1243,OR=198880,PL=0,JI=0,LA=0,DU=19 Content-Length: 0 Nov 24 17:01:54.738: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [217.20.39.101]:5060, local_address:[ext.ext.ext.ext] Nov 24 17:01:54.742: //63/842E0F800002/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Nov 24 17:01:54.742: //63/842E0F800002/SIP/Info/sipSPISendBye: Associated container=0x32B05824 to Bye Nov 24 17:01:54.742: //63/842E0F800002/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Nov 24 17:01:54.742: //63/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:01:54.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x2BE88DF0, addr=10.0.2.52, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x0 Nov 24 17:01:54.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:54.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:54.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:54.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:01:54.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2BE88DF0 Nov 24 17:01:54.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2BE88DF0, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:01:54.742: //64/842E0F800002/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Nov 24 17:01:54.742: //64/842E0F800002/SIP/Info/sipSPISendBye: Associated container=0x32B0398C to Bye Nov 24 17:01:54.742: //64/842E0F800002/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Nov 24 17:01:54.742: //64/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:01:54.742: //64/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x2D1A4844, addr=217.20.39.101, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x0 Nov 24 17:01:54.742: //64/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:54.742: //64/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:54.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:217.20.39.101, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:54.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328F04B8 is already on connection=0x3223A93C context_list Nov 24 17:01:54.742: //64/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2D1A4844 Nov 24 17:01:54.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2D1A4844, addr=217.20.39.101, port=5060, local_addr=ext.ext.ext.ext, connId=6 for UDP Nov 24 17:01:54.742: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Nov 24 17:01:54.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x31C7E00C Nov 24 17:01:54.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x31C7E00C, addr=217.20.39.101, port=5060, local_addr=ext.ext.ext.ext, connid=6, transport=UDP Nov 24 17:01:54.742: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 conn Id 6 Nov 24 17:01:54.742: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Nov 24 17:01:54.742: //64/842E0F800002/SIP/Info/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK131530 from via branch list Nov 24 17:01:54.742: //64/842E0F800002/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 200 OK Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK131530 From: "OrbTalk 0100" ;tag=12A6C8-226 To: ;tag=1901410832 Call-ID: 5B498A64-733211E4-805A8E78-B6AD319D@ext.ext.ext.ext Timestamp: 1416848514 CSeq: 103 BYE Content-Length: 0 Nov 24 17:01:54.742: //64/842E0F800002/SIP/Info/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX Nov 24 17:01:54.742: //64/842E0F800002/SIP/Info/sipSPIDeferCallClose: Not split dataplane, bail Nov 24 17:01:54.742: //64/842E0F800002/SIP/Info/sipSPIWaitForStatsBforeCallClose: Not split dataplane, bail Nov 24 17:01:54.742: //64/842E0F800002/SIP/Info/sipSPICallCloseAfterFinalStat: sipSPICallCloseAfterFinalStat: Nov 24 17:01:54.742: //64/842E0F800002/SIP/Info/sipSPIIcpifUpdate: CallState: 4 Playout: 0 DiscTime:125179 ConnTime 123174 Nov 24 17:01:54.742: //64/842E0F800002/SIP/Media/sipSPIHandleDestroyRtpSession: stream:30037740 Nov 24 17:01:54.742: //64/842E0F800002/SIP/State/sipSPIChangeState: 0x328F04B8 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE) Nov 24 17:01:54.742: //64/842E0F800002/SIP/Call/sipSPICallInfo: The Call Setup Information is: Call Control Block (CCB) : 0x0x328F04B8 State of The Call : STATE_DEAD TCP Sockets Used : NO Calling Number : 441215550123 Called Number : 447777123456 Source IP Address (Sig ): ext.ext.ext.ext Destn SIP Req Addr:Port : 217.20.39.101:5060 Destn SIP Resp Addr:Port : 217.20.39.101:5060 Destination Name : sip.orbtalk.co.uk Nov 24 17:01:54.742: //64/842E0F800002/SIP/Call/sipSPIMediaCallInfo: Number of Media Streams: 1 Media Stream : 1 Negotiated Codec : g711alaw Negotiated Codec Bytes : 160 Nego. Codec payload : 8 (tx), 8 (rx) Negotiated Dtmf-relay : 6 Dtmf-relay Payload : 101 (tx), 101 (rx) Source IP Address (Media): ext.ext.ext.ext Source IP Port (Media): 16424 Destn IP Address (Media): 217.20.39.102 Destn IP Port (Media): 59300 Orig Destn IP Address:Port (Media): [ - ]:0 Nov 24 17:01:54.742: //64/842E0F800002/SIP/Call/sipSPICallInfo: Disconnect Cause (CC) : 102 Disconnect Cause (SIP) : 200 Nov 24 17:01:54.742: //64/842E0F800002/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 40 Nov 24 17:01:54.742: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[58] removed. Nov 24 17:01:54.742: //64/842E0F800002/SIP/Info/sipSPIUdeleteCcbFromUACTable: ****Deleting from UAC table. Nov 24 17:01:54.742: //64/842E0F800002/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x328F04B8 key=5B498A64-733211E4-805A8E78-B6AD319D@ext.ext.ext.ext Nov 24 17:01:54.742: //64/842E0F800002/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd Nov 24 17:01:54.746: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x31C7E00C, addr=217.20.39.101, port=5060, local_addr=ext.ext.ext.ext, unregistering context=0x328F04B8 Nov 24 17:01:54.746: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstancePurgeContextInConnection: Purging context gcb=0x328F04B8 from the connection=0x3223A93C context list Nov 24 17:01:54.746: //64/842E0F800002/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed Nov 24 17:01:54.746: //64/842E0F800002/SIP/Info/ccsip_offer_ans_delete: Nov 24 17:01:54.746: //64/842E0F800002/SIP/Info/ccsip_iwf_delete: Nov 24 17:01:54.746: //64/842E0F800002/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 0x328F04B8 Nov 24 17:01:54.746: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[58] Nov 24 17:01:54.746: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:441215550123@10.0.2.52:5060 SIP/2.0 Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK121971 From: ;tag=12BBF4-1D21 To: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 User-Agent: Cisco-SIPGateway/IOS-15.2.3.T1 Max-Forwards: 70 Timestamp: 1416848514 CSeq: 101 BYE Reason: Q.850;cause=86 P-RTP-Stat: PS=1228,OS=196480,PR=341,OR=54560,PL=0,JI=0,LA=0,DU=19 Content-Length: 0 Nov 24 17:01:54.746: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:217.20.39.101;did=6f6.88941606 SIP/2.0 Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK131530 From: "OrbTalk 0100" ;tag=12A6C8-226 To: ;tag=1901410832 Date: Mon, 24 Nov 2014 17:01:25 GMT Call-ID: 5B498A64-733211E4-805A8E78-B6AD319D@ext.ext.ext.ext User-Agent: Cisco-SIPGateway/IOS-15.2.3.T1 Max-Forwards: 70 P-Asserted-Identity: "OrbTalk 0100" Timestamp: 1416848514 CSeq: 103 BYE Proxy-Authorization: Digest username="1111111",realm="sip.orbtalk.co.uk",uri="sip:217.20.39.101;did=6f6.88941606",response="7fd368e5c2912a6a05240bd85e319b58",nonce="547365917f9b160f5ece82d1592ab65a88901ace",algorithm=md5 Reason: Q.850;cause=102 P-RTP-Stat: PS=341,OS=54560,PR=1243,OR=198880,PL=0,JI=0,LA=0,DU=19 Content-Length: 0 Nov 24 17:01:55.410: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [217.20.39.101]:5060, local_address:[ext.ext.ext.ext] Nov 24 17:01:55.410: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Nov 24 17:01:55.410: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x31C7E00C Nov 24 17:01:55.410: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x31C7E00C, addr=217.20.39.101, port=5060, local_addr=ext.ext.ext.ext, connid=6, transport=UDP Nov 24 17:01:55.410: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 connId 6 Nov 24 17:01:55.410: //-1/xxxxxxxxxxxx/SIP/Inf o/ccsip_new_msg_preprocessor: Checking Invite Dialog Nov 24 17:01:55.410: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 404 Not here Via: SIP/2.0/UDP ext.ext.ext.ext:5060;received=ext.ext.ext.ext;rport=54689;branch=z9hG4bK131530 From: "OrbTalk 0100" ;tag=12A6C8-226 To: ;tag=1901410832 Call-ID: 5B498A64-733211E4-805A8E78-B6AD319D@ext.ext.ext.ext CSeq: 103 BYE Server: OrbTalk Content-Length: 0 Nov 24 17:01:55.410: //-1/xxxxxxxxxxxx/SIP/Error/sipSPILocateInviteDialogCCB: Could not find ccb for response Nov 24 17:01:55.970: //63/842E0F800002/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Nov 24 17:01:55.970: //63/842E0F800002/SIP/Info/sipSPISendBye: Associated container=0x32B05824 to Bye Nov 24 17:01:55.970: //63/842E0F800002/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Nov 24 17:01:55.970: //63/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:01:55.970: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x2BE88DF0, addr=10.0.2.52, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x0 Nov 24 17:01:55.970: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:55.970: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:55.970: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:55.970: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:01:55.970: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2BE88DF0 Nov 24 17:01:55.970: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2BE88DF0, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:01:55.970: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:441215550123@10.0.2.52:5060 SIP/2.0 Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK121971 From: ;tag=12BBF4-1D21 To: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 User-Agent: Cisco-SIPGateway/IOS-15.2.3.T1 Max-Forwards: 70 Timestamp: 1416848515 CSeq: 101 BYE Reason: Q.850;cause=86 P-RTP-Stat: PS=1228,OS=196480,PR=341,OR=54560,PL=0,JI=0,LA=0,DU=19 Content-Length: 0 Nov 24 17:01:57.742: //63/842E0F800002/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Nov 24 17:01:57.742: //63/842E0F800002/SIP/Info/sipSPISendBye: Associated container=0x32B05824 to Bye Nov 24 17:01:57.742: //63/842E0F800002/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Nov 24 17:01:57.742: //63/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:01:57.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x2BE88DF0, addr=10.0.2.52, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x0 Nov 24 17:01:57.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:01:57.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:01:57.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:01:57.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:01:57.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2BE88DF0 Nov 24 17:01:57.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2BE88DF0, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:01:57.742: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:441215550123@10.0.2.52:5060 SIP/2.0 Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK121971 From: ;tag=12BBF4-1D21 To: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 User-Agent: Cisco-SIPGateway/IOS-15.2.3.T1 Max-Forwards: 70 Timestamp: 1416848517 CSeq: 101 BYE Reason: Q.850;cause=86 P-RTP-Stat: PS=1228,OS=196480,PR=341,OR=54560,PL=0,JI=0,LA=0,DU=19 Content-Length: 0 Nov 24 17:02:01.742: //63/842E0F800002/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Nov 24 17:02:01.742: //63/842E0F800002/SIP/Info/sipSPISendBye: Associated container=0x32B05824 to Bye Nov 24 17:02:01.742: //63/842E0F800002/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Nov 24 17:02:01.742: //63/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:02:01.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x2BE88DF0, addr=10.0.2.52, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x0 Nov 24 17:02:01.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:02:01.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:02:01.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:02:01.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:02:01.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2BE88DF0 Nov 24 17:02:01.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2BE88DF0, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:02:01.742: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:441215550123@10.0.2.52:5060 SIP/2.0 Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK121971 From: ;tag=12BBF4-1D21 To: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 User-Agent: Cisco-SIPGateway/IOS-15.2.3.T1 Max-Forwards: 70 Timestamp: 1416848521 CSeq: 101 BYE Reason: Q.850;cause=86 P-RTP-Stat: PS=1228,OS=196480,PR=341,OR=54560,PL=0,JI=0,LA=0,DU=19 Content-Length: 0 Nov 24 17:02:05.742: //63/842E0F800002/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Nov 24 17:02:05.742: //63/842E0F800002/SIP/Info/sipSPISendBye: Associated container=0x32B05824 to Bye Nov 24 17:02:05.742: //63/842E0F800002/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Nov 24 17:02:05.742: //63/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:02:05.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x2BE88DF0, addr=10.0.2.52, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x0 Nov 24 17:02:05.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:02:05.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:02:05.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:02:05.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:02:05.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2BE88DF0 Nov 24 17:02:05.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2BE88DF0, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:02:05.742: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:441215550123@10.0.2.52:5060 SIP/2.0 Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK121971 From: ;tag=12BBF4-1D21 To: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 User-Agent: Cisco-SIPGateway/IOS-15.2.3.T1 Max-Forwards: 70 Timestamp: 1416848525 CSeq: 101 BYE Reason: Q.850;cause=86 P-RTP-Stat: PS=1228,OS=196480,PR=341,OR=54560,PL=0,JI=0,LA=0,DU=19 Content-Length: 0 Nov 24 17:02:09.742: //63/842E0F800002/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Nov 24 17:02:09.742: //63/842E0F800002/SIP/Info/sipSPISendBye: Associated container=0x32B05824 to Bye Nov 24 17:02:09.742: //63/842E0F800002/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Nov 24 17:02:09.742: //63/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:02:09.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x2BE88DF0, addr=10.0.2.52, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x0 Nov 24 17:02:09.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:02:09.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:02:09.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:02:09.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:02:09.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2BE88DF0 Nov 24 17:02:09.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2BE88DF0, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:02:09.742: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:441215550123@10.0.2.52:5060 SIP/2.0 Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK121971 From: ;tag=12BBF4-1D21 To: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 User-Agent: Cisco-SIPGateway/IOS-15.2.3.T1 Max-Forwards: 70 Timestamp: 1416848529 CSeq: 101 BYE Reason: Q.850;cause=86 P-RTP-Stat: PS=1228,OS=196480,PR=341,OR=54560,PL=0,JI=0,LA=0,DU=19 Content-Length: 0 Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [217.20.39.101]:5060, local_address:[ - ] Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x31C7E00C Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x31C7E00C, addr=217.20.39.101, port=5060, local_addr=, connid=2, transport=UDP Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 connId 2 Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Received: OPTIONS sip:ext.ext.ext.ext:49721 SIP/2.0 Via: SIP/2.0/UDP 217.20.39.101:5060;branch=z9hG4bK2957027 From: sip:pinger@sip.orbtalk.co.uk;tag=b202de21 To: sip:ext.ext.ext.ext:49721 Call-ID: de8a5df3-b2846205-4f2764@217.20.39.101 CSeq: 1 OPTIONS Max-Forwards: 70 Content-Length: 0 Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x328F04B8) with key=[60] to table Nov 24 17:02:10.650: //-1/000000000000/SIP/Info/ccsip_offer_ans_init: Nov 24 17:02:10.650: //-1/000000000000/SIP/Info/ccsip_iwf_init: Nov 24 17:02:10.650: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init: Nov 24 17:02:10.650: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization: Entry... Nov 24 17:02:10.650: //-1/000000000000/SIP/Info/ccsip_ipip_media_forking_init: MF: Queue is initialised.. Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 217.20.39.101,Port 5060, Transport 1, SentBy Port 5060 Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop() Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: ip_best_local_address ext.ext.ext.ext for SIP Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr ext.ext.ext.ext Nov 24 17:02:10.650: //-1/76CA8A6A805F/SIP/State/sipSPIChangeState: 0x328F04B8 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 217.20.39.101,Port 5060, Transport 1, SentBy Port 5060 Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone ASD to SIP default timezone = GMT Nov 24 17:02:10.650: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 217.20.39.101,Port 5060, Transport 1, SentBy Port 5060 Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/ccsipInitPldCallingInfo: non-numeric calling number: pinger Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL Conversion failed for Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : pinger Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Error/sipSPIGetPeerByCalledPartyId: input arg error Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Error/sipSPIUpdateCallInfo: input argument error Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetCallConfig: Non dial peer leg - using RTP Supported Codecs Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 18 Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 0 Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 8 Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 9 Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 4 Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 2 Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 15 Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 255 Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Error/ccsip_ipip_media_forking_update_preferred_codec: MF: Not a Forked SIP leg.. Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0 Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Info/sipSPIGetModemConfig: From Config: Modem NSE payload = 100, Passthrough = 4, Modem relay = 0, Gw-Xid = 1 SPRT latency 200, SPRT Retries = 12, Dict Size = 1024 String Len = 32, Compress dir = 3 Nov 24 17:02:10.650: //69/76CA8A6A805F/SIP/Error/ccsip_ipip_media_forking_anchor_leg_config: MF: Dial-peer is absent.. Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/sipSPIMFChangeState: MF: Prev state = 0 & New state = -1 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/ccsip_ipip_media_forking_anchor_leg_reset: MF: Anchor leg config reset done... Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/populate_vcc_data: Non dial peer leg - using RTP Supported Codecs Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 18 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 0 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 8 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 9 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 4 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 2 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 15 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/populate_vcc_data: RTP Preferred Codecs supported by GW 255 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:2 tag:0 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Error/sipSPI_ipip_build_consolidated_header_list: No headers associated with passthrulist tag: 0 and copylist tag: 0 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Nov 24 17:02:10.654: //-1/xxxxxxxxxxxx/SIP/I nfo/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 ext.ext.ext.ext for SIP Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = ext.ext.ext.ext Nov 24 17:02:10.654: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop() Nov 24 17:02:10.654: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: ip_best_local_address ext.ext.ext.ext for SIP Nov 24 17:02:10.654: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr ext.ext.ext.ext Nov 24 17:02:10.654: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_OPTIONS_RESP Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/sact_idle_new_message_options: ccsip_api_options_ind returned: SIP_SUCCESS Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/State/sipSPIChangeState: 0x328F04B8 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE) Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table. Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x328F04B8 key=de8a5df3-b2846205-4f2764@217.20.39.101 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 45 to table Nov 24 17:02:10.654: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 38 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Info/sipSPISendOptionsResponse: Associated container=0x32B03B9C to Options Response Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Transport/sipSPITransportSendMessage: msg=0x2BACF5FC, addr=217.20.39.101, port=5060, sentBy_port=5060, local_addr=, is_req=0, transport=1, switch=0, callBack=0x255EDCFC Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x2BACF5FC to default port=5060 Nov 24 17:02:10.654: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:217.20.39.101, rport:5060 with laddr: Nov 24 17:02:10.654: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x328F04B8 with connection=0x317E6B84 context list Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x2BACF5FC Nov 24 17:02:10.654: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2BACF5FC, addr=217.20.39.101, port=5060, local_addr=, connId=2 for UDP Nov 24 17:02:10.654: //69/76CA8A6A805F/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 200 OK Via: SIP/2.0/UDP 217.20.39.101:5060;branch=z9hG4bK2957027 From: sip:pinger@sip.orbtalk.co.uk;tag=b202de21 To: sip:ext.ext.ext.ext:49721;tag=1357F8-1629 Date: Mon, 24 Nov 2014 17:02:10 GMT Call-ID: de8a5df3-b2846205-4f2764@217.20.39.101 Server: Cisco-SIPGateway/IOS-15.2.3.T1 CSeq: 1 OPTIONS Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Accept: application/sdp Supported: timer,resource-priority,replaces,sdp-anat Content-Type: application/sdp Content-Length: 167 v=0 o=CiscoSystemsSIP-GW-UserAgent 2123 3396 IN IP4 ext.ext.ext.ext s=SIP Call c=IN IP4 ext.ext.ext.ext t=0 0 m=audio 0 RTP/AVP 18 0 8 9 4 2 15 c=IN IP4 ext.ext.ext.ext Nov 24 17:02:12.134: //68/6497BDB7805E/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 44 Nov 24 17:02:12.134: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[59] removed. Nov 24 17:02:12.134: //68/6497BDB7805E/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table. Nov 24 17:02:12.134: //68/6497BDB7805E/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x328FC3E8 key=de8a5df3-61846205-6d2764@217.20.39.101 Nov 24 17:02:12.134: //68/6497BDB7805E/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table. Nov 24 17:02:12.134: //68/6497BDB7805E/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd Nov 24 17:02:12.134: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x31C7E00C, addr=217.20.39.101, port=5060, local_addr=, unregistering context=0x328FC3E8 Nov 24 17:02:12.134: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstancePurgeContextInConnection: Purging context gcb=0x328FC3E8 from the connection=0x317E6B84 context list Nov 24 17:02:12.134: //68/6497BDB7805E/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed Nov 24 17:02:12.134: //68/6497BDB7805E/SIP/Info/ccsip_offer_ans_delete: Nov 24 17:02:12.134: //68/6497BDB7805E/SIP/Info/ccsip_iwf_delete: Nov 24 17:02:12.134: //68/6497BDB7805E/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 0x328FC3E8 Nov 24 17:02:12.710: %SEC-6-IPACCESSLOGP: list outside2in denied tcp 60.12.148.185(0) -> ext.ext.ext.ext(0), 1 packet Nov 24 17:02:13.882: //63/842E0F800002/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Nov 24 17:02:13.882: //63/842E0F800002/SIP/Info/sipSPISendBye: Associated container=0x32B05824 to Bye Nov 24 17:02:13.882: //63/842E0F800002/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Nov 24 17:02:13.882: //63/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:02:13.882: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x32F08564, addr=10.0.2.52, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x0 Nov 24 17:02:13.882: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:02:13.882: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:02:13.882: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:02:13.882: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:02:13.882: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x32F08564 Nov 24 17:02:13.882: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x32F08564, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:02:13.882: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:441215550123@10.0.2.52:5060 SIP/2.0 Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK121971 From: ;tag=12BBF4-1D21 To: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 User-Agent: Cisco-SIPGateway/IOS-15.2.3.T1 Max-Forwards: 70 Timestamp: 1416848533 CSeq: 101 BYE Reason: Q.850;cause=86 P-RTP-Stat: PS=1228,OS=196480,PR=341,OR=54560,PL=0,JI=0,LA=0,DU=19 Content-Length: 0 Nov 24 17:02:15.690: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnAgeing: Holder=0x32E4C998 Connection=0x31A2FF00, addr=10.0.2.52, port=5060, connid=5 has been REFRESHED Nov 24 17:02:15.690: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x32E4C998,addr=10.0.2.52 Nov 24 17:02:17.742: //63/842E0F800002/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Nov 24 17:02:17.742: //63/842E0F800002/SIP/Info/sipSPISendBye: Associated container=0x32B05824 to Bye Nov 24 17:02:17.742: //63/842E0F800002/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Nov 24 17:02:17.742: //63/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:02:17.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x32F08564, addr=10.0.2.52, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x0 Nov 24 17:02:17.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:02:17.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:02:17.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:02:17.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:02:17.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x32F08564 Nov 24 17:02:17.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x32F08564, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:02:17.742: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:441215550123@10.0.2.52:5060 SIP/2.0 Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK121971 From: ;tag=12BBF4-1D21 To: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 User-Agent: Cisco-SIPGateway/IOS-15.2.3.T1 Max-Forwards: 70 Timestamp: 1416848537 CSeq: 101 BYE Reason: Q.850;cause=86 P-RTP-Stat: PS=1228,OS=196480,PR=341,OR=54560,PL=0,JI=0,LA=0,DU=19 Content-Length: 0 Nov 24 17:02:21.742: //63/842E0F800002/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Nov 24 17:02:21.742: //63/842E0F800002/SIP/Info/sipSPISendBye: Associated container=0x32B05824 to Bye Nov 24 17:02:21.742: //63/842E0F800002/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Nov 24 17:02:21.742: //63/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:02:21.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x32F08564, addr=10.0.2.52, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x0 Nov 24 17:02:21.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:02:21.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:02:21.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:02:21.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:02:21.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x32F08564 Nov 24 17:02:21.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x32F08564, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:02:21.742: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:441215550123@10.0.2.52:5060 SIP/2.0 Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK121971 From: ;tag=12BBF4-1D21 To: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 User-Agent: Cisco-SIPGateway/IOS-15.2.3.T1 Max-Forwards: 70 Timestamp: 1416848541 CSeq: 101 BYE Reason: Q.850;cause=86 P-RTP-Stat: PS=1228,OS=196480,PR=341,OR=54560,PL=0,JI=0,LA=0,DU=19 Content-Length: 0 Nov 24 17:02:25.742: //63/842E0F800002/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Nov 24 17:02:25.742: //63/842E0F800002/SIP/Info/sipSPISendBye: Associated container=0x32B05824 to Bye Nov 24 17:02:25.742: //63/842E0F800002/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Nov 24 17:02:25.742: //63/842E0F800002/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE Nov 24 17:02:25.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: msg=0x32F08564, addr=10.0.2.52, port=5060, sentBy_port=0, local_addr=ext.ext.ext.ext, is_req=1, transport=1, switch=0, callBack=0x0 Nov 24 17:02:25.742: //63/842E0F800002/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Nov 24 17:02:25.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Nov 24 17:02:25.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.2.52, rport:5060 with laddr:ext.ext.ext.ext Nov 24 17:02:25.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x328E4588 is already on connection=0x31A2FF00 context_list Nov 24 17:02:25.742: //63/842E0F800002/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x32F08564 Nov 24 17:02:25.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x32F08564, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, connId=5 for UDP Nov 24 17:02:25.742: //63/842E0F800002/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:441215550123@10.0.2.52:5060 SIP/2.0 Via: SIP/2.0/UDP ext.ext.ext.ext:5060;branch=z9hG4bK121971 From: ;tag=12BBF4-1D21 To: "OrbTalk 0100" ;tag=2695074~558b08dc-be7e-476e-8dc0-eeef8522c7f1-50254890 Date: Mon, 24 Nov 2014 17:01:24 GMT Call-ID: 842e0f80-47316464-31346-3402000a@10.0.2.52 User-Agent: Cisco-SIPGateway/IOS-15.2.3.T1 Max-Forwards: 70 Timestamp: 1416848545 CSeq: 101 BYE Reason: Q.850;cause=86 P-RTP-Stat: PS=1228,OS=196480,PR=341,OR=54560,PL=0,JI=0,LA=0,DU=19 Content-Length: 0 Nov 24 17:02:29.742: //63/842E0F800002/SIP/Error/act_disconnecting_wait_200: Out of retries Nov 24 17:02:29.742: //63/842E0F800002/SIP/Info/sipSPIDeferCallClose: Not split dataplane, bail Nov 24 17:02:29.742: //63/842E0F800002/SIP/Info/sipSPIWaitForStatsBforeCallClose: Not split dataplane, bail Nov 24 17:02:29.742: //63/842E0F800002/SIP/Info/sipSPICallCloseAfterFinalStat: sipSPICallCloseAfterFinalStat: Nov 24 17:02:29.742: //63/842E0F800002/SIP/Info/sipSPIIcpifUpdate: CallState: 3 Playout: 0 DiscTime:128679 ConnTime 123175 Nov 24 17:02:29.742: //63/842E0F800002/SIP/Media/sipSPIHandleDestroyRtpSession: stream:31EDCFA0 Nov 24 17:02:29.742: //63/842E0F800002/SIP/State/sipSPIChangeState: 0x328E4588 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE) Nov 24 17:02:29.742: //63/842E0F800002/SIP/Call/sipSPICallInfo: The Call Setup Information is: Call Control Block (CCB) : 0x0x328E4588 State of The Call : STATE_DEAD TCP Sockets Used : NO Calling Number : 441215550123 Called Number : 447777123456 Source IP Address (Sig ): ext.ext.ext.ext Destn SIP Req Addr:Port : 10.0.2.52:5060 Destn SIP Resp Addr:Port : 10.0.2.52:5060 Destination Name : 10.0.2.52 Nov 24 17:02:29.742: //63/842E0F800002/SIP/Call/sipSPIMediaCallInfo: Number of Media Streams: 1 Media Stream : 1 Negotiated Codec : g711alaw Negotiated Codec Bytes : 160 Nego. Codec payload : 8 (tx), 8 (rx) Negotiated Dtmf-relay : 0 Dtmf-relay Payload : 0 (tx), 0 (rx) Source IP Address (Media): ext.ext.ext.ext Source IP Port (Media): 16422 Destn IP Address (Media): 10.0.0.2 Destn IP Port (Media): 16420 Orig Destn IP Address:Port (Media): [ - ]:0 Nov 24 17:02:29.742: //63/842E0F800002/SIP/Call/sipSPICallInfo: Disconnect Cause (CC) : 86 Disconnect Cause (SIP) : 500 Nov 24 17:02:29.742: //63/842E0F800002/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 3F Nov 24 17:02:29.742: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[57] removed. Nov 24 17:02:29.742: //63/842E0F800002/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table. Nov 24 17:02:29.742: //63/842E0F800002/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x328E4588 key=842e0f80-47316464-31346-3402000a@10.0.2.52447777123456 Nov 24 17:02:29.742: //63/842E0F800002/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table. Nov 24 17:02:29.742: //63/842E0F800002/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x328E4588 key=842e0f80-47316464-31346-3402000a@10.0.2.5212BBF4-1D21 Nov 24 17:02:29.742: //63/842E0F800002/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd Nov 24 17:02:29.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x31C7E00C, addr=10.0.2.52, port=5060, local_addr=ext.ext.ext.ext, unregistering context=0x328E4588 Nov 24 17:02:29.742: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstancePurgeContextInConnection: Purging context gcb=0x328E4588 from the connection=0x31A2FF00 context list Nov 24 17:02:29.742: //63/842E0F800002/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed Nov 24 17:02:29.742: //63/842E0F800002/SIP/Info/ccsip_offer_ans_delete: Nov 24 17:02:29.742: //63/842E0F800002/SIP/Info/ccsip_iwf_delete: Nov 24 17:02:29.742: //63/842E0F800002/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 0x328E4588