Feb 19 20:19:34.152: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToTable: Added context(0x2B6BA190) with key=[23214] to table Feb 19 20:19:34.152: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_service_init: Feb 19 20:19:34.152: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_service_init: Feb 19 20:19:34.152: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_forking_init: MF: Queue is initialised.. Feb 19 20:19:34.152: //28231/000000000000/SIP/State/sipSPIChangeState: 0x2B6BA190 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/critical/32768/ccsip_ipip_media_forking_read_from_TDContainer: MF: Unable to read data from TD Container.. Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/critical/32768/ccsip_ipip_media_forking_forked_leg_config: MF: TD container cannot be read/container is NULL. Setting of forked call leg failed.. Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 1, Event Id: EV_UNDEFINED Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: IWF Event: E_SIP_IWF_EV_SET_MODE Feb 19 20:19:34.152: //28231/000000000000/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_SET_MODE Feb 19 20:19:34.152: //28231/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/is_mode_sip_sip_md_snr: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/is_mode_sip_sip_ed_snr: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/is_mode_sip_sip_md: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/is_mode_sip_sip_ed: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/is_mode_sip_h32x_in_set_mode: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/is_mode_sip_h323_in_set_mode: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/is_mode_sip_sccp_in_set_mode: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/is_mode_sip_sccp_in_set_mode: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/8192/sip_iwf_def_set_mode_hdlr: Setting SPI mode to SIP-TDM Feb 19 20:19:34.152: //28231/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_sccp_early_dialog_container Feb 19 20:19:34.152: //28231/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/ccsip_iwf_handle_peer_event: Return value: SIP_IWF_SUCCESS Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 3, Event Id: CC_EV_IF_DIAG_DONE Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: IWF Event: E_SIP_IWF_EV_SET_FLOW_MODE Feb 19 20:19:34.152: //28231/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sccp_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_SET_FLOW_MODE Feb 19 20:19:34.152: //28231/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/is_fa2ft_md_flow_mode_transition: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/is_fa2ft_flow_mode_transition: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/ccsip_get_flow_mode_frm_set_flow_mode_ev: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/is_fa2ft_flow_mode_transition: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/ccsip_get_flow_mode_frm_set_flow_mode_ev: Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/verbose/4096/ccsip_iwf_process_event: IWF - cnfsm ret 2 Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/ccsip_iwf_handle_peer_event: Return value: SIP_IWF_SUCCESS Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/ccsip_call_setup_request: Before processing SETUP REQccb->pld.flags_ipip = 200 Feb 19 20:19:34.152: //28231/000000000000/SIP/Info/info/4096/ccsip_call_setup_request: After processing SETUP REQccb->pld.flags_ipip = 200 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_call_setup_request: Number Translation Set For Called-Number Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:34.152: //-1/xxxxxxxxxxxx/SIP/Info/verbose/5120/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : bumblebee.vtnoc.net target_port : 5060
Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/4096/sipSPIUaddccCallIdToTable: Adding call id 6E47 to table Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/notify/131072/ccsip_call_setup_request: Incrementing call counter to [1] in dial-peer [13] Feb 19 20:19:34.152: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_SETUP Feb 19 20:19:34.152: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 2 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/2049/sipSPIGetCallConfig: preferred_codec set[0] type :No Codec bytes: 0 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/2048/sipSPI_ipip_store_config_info: Setting mid_call_config_info = 0x0 for callid = 28231 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/8192/sipSPIGetCallConfig: Media forking disabled Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/32768/sipSPIGetCallConfig: Media Antitrombone disabled Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/notify/131072/sipSPICanSetFallbackFlag: Local Fallback is not active Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/8192/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/2304/sipSPISetMediaFlowMode: xcoder high-density disabled Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/8192/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/4/update_video_params_from_config: Checking Video Type Rate=-1 video_codec_allowed=1F Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/12288/sipSPIGetModemInfoPerCall: peer_callID=28230 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/critical/32768/ccsip_ipip_media_forking_update_preferred_codec: MF: Not a Forked SIP leg.. Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/8704/sipSPIGetCallConfig: Incoming: No defer BYE for last call stats Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/8192/sipSPIGetCallConfig: Media forking disabled Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/34816/ccsip_ipip_media_forking_anchor_leg_config: MF: en_p->encap_s.voIP.voipPeerCfgMediaClass = 0 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/critical/34816/ccsip_ipip_media_forking_anchor_leg_config: MF: Dial-peer has no media class recorder. Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/36864/sipSPIMFChangeState: MF: Prev state = 0 & New state = -1 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/32768/ccsip_ipip_media_forking_anchor_leg_reset: MF: Anchor leg config reset done... Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/32768/ccsip_ipip_media_forking_intra_frame_request_config: MF: FIR en_p->encap_s.voIP.voipPeerCfgMediaClass = 0 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/critical/11264/ccsipInitDSCPPolicyInfo: No DSCP Profile configured, No RPH 2 DSCP Mapping and DSCP policing Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/8192/sipSPIGetCallConfig: Initilise the DSCP policy Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/8192/sipSPICheckFAAnatAssymetricOrDO2EO: Not a SIP-SIP call or not in FA mode Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/notify/8192/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/10240/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/2048/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/notify/10240/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/5120/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/1/preprocessSetup: This is a not a SIGO Call -, could be DM call Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sccp_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_INIT_CALL_SETUP Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_iwf_process_event: IWF - cnfsm ret 2 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/notify/4096/preprocessSetup: SIP-TDM or TCL/VXML app case Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/notify/4096/sip_gw_pre_setup_update_stream_media_direction: peer_callID = 28230 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/critical/4097/sip_gw_pre_setup_update_stream_media_direction: peer_channels/stream is NULL Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/notify/1/sip_gw_pre_setup_add_sdp_container: DNS/ENUM resolution required; Deferred Creating SDP Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/131072/sipSPIBwCacUpdateAccountedBw: bwcac update accounted BW Option 0 flow mode flow-through audio bw 0 bps video bw 0 bps fax bw 0 bps total bw 0 bps accounted bw 0 bps Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/131072/sipSPIBwCacUpdateInterfaceBw: bwcac acquiring interface BVI255 bw 0 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/131072/sipSPIBwCacUpdateAccountedBw: bwcac update accounted bw (initial offer) accounted bw set to 0 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/133120/sipSPIBwCacIsDialPeerBwAvailable: bwcac NOP dial-peer bw available tag 13 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/notify/1/sipSPIBwCacIsInterfaceBwAvailable: bwcac interface bw threshold not configured Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/131072/sipSPIBwCacVerifyBwThreshold: bwcac verify bw threshold, bw available allow call total bw 0 bps Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/critical/8192/sipSPIValidateGtd: Signal Forward disabled Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/critical/8192/sipSPIValidateTunnelData: RawMsg/QSIG Tunneling Not Enabled Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/critical/10240/sipSPIAddMLPPServicesInfo: No MLP Info available on incoming leg Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/3072/sipSPIPreprocessUriFormat: Url cfg for 1: 2,phone-ctxt=FALSE Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/9216/sipSPIAddCiscoGcid: Gcid value not set - not adding header. Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/4096/sipSPIAddPrivacyandIdentityInfo: ccb->local_host_name,ccb->src_addr_str is NULL Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/critical/2048/sipSPICompareHistoryInfoWithMatchedDialpeer: call-route history-info CLI not enabled Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Error/sipSPI_ipip_set_history_info_header: ccb->src_addr_str is NULL Feb 19 20:19:34.152: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_DNS_RESOLVE Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/State/sipSPIChangeState: 0x2B6BA190 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_SENT_DNS) Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/State/sipSPIChangeState: 0x2B6BA190 : State change from (STATE_IDLE, SUBSTATE_SENT_DNS) to (STATE_IDLE, SUBSTATE_SENT_DNS) Feb 19 20:19:34.152: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 12.1.2.3 for SIP Feb 19 20:19:34.152: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 12.1.2.3 for SIP Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 12.1.2.3 Feb 19 20:19:34.152: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 12.1.2.3 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/4096/sipSPIUaddCcbToUACTable: ****Adding to UAC table.0x2B6BA190 ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to table. ccb=0x2B6BA190 key=ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 balance 1 Feb 19 20:19:34.152: //28231/EB59E1D3B413/SIP/Info/verbose/12288/sipSPIUsetBillingProfile: sipCallId for billing records = ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 Feb 19 20:19:34.152: //-1/xxxxxxxxxxxx/SIP/Info/notify/8192/sip_dns_type_srv_query: TYPE SRV query for _sip._udp.bumblebee.vtnoc.net and type:1 Feb 19 20:19:34.180: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/sip_dns_type_srv_query: Server Name bumblebee.vtnoc.net Priority 0 Weight 1 Port 5060 Feb 19 20:19:34.180: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/sip_dns_type_srv_query: Server Name soundwave.vtnoc.net Priority 1 Weight 1 Port 5060 Feb 19 20:19:34.180: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/sip_dns_type_srv_query: Server Name ratchet.vtnoc.net Priority 1 Weight 1 Port 5060 Feb 19 20:19:34.180: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/sip_dns_type_srv_query: Server Name slingshot.vtnoc.net Priority 1 Weight 1 Port 5060 Feb 19 20:19:34.180: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sip_dns_type_srv_query: Calculating Random Number : 26686 factor 65535 value 0 Feb 19 20:19:34.180: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/sip_dns_type_srv_query: Selected Server is bumblebee.vtnoc.net Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/notify/8192/sip_dns_type_a_query: TYPE A query successful for bumblebee.vtnoc.net Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/sip_dns_type_a_query: ttl for A records = 177 seconds Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/sip_dns_type_srv_query: IP Address of bumblebee.vtnoc.net is:
Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/sip_dns_type_srv_query: 66.147.235.3
Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/sip_dns_type_srv_query: ttl for SRV records = 623seconds Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 43 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/State/sipSPIChangeState: 0x2B6BA190 : State change from (STATE_IDLE, SUBSTATE_SENT_DNS) to (STATE_IDLE, SUBSTATE_NONE) Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/sipSPICacheHostToCCB: sipSPICacheHostToCCB dnsResponse.num_hosts = 1 Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/sipSPICacheHostToCCB: IP Address No. 1, IP address 66.147.235.3 Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 12.1.2.3 for SIP Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 12.1.2.3 for SIP Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 12.1.2.3 Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 12.1.2.3 Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 12.1.2.3 for SIP Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 12.1.2.3 for SIP Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 12.1.2.3 Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 12.1.2.3 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/131072/sipSPIRscmsmAvail: Value returned by check is = 0 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/critical/2048/sipSPICompareHistoryInfoWithMatchedDialpeer: call-route history-info CLI not enabled Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/critical/1024/sipSPI_ipip_set_history_info_header: No HI header recvd from container Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/verbose/8192/sipSPIAddPrivacyandIdentityInfo: Removing "id" value from Privacy Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: peer_tag=13 Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 12.1.2.3 for SIP Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 12.1.2.3 for SIP Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 12.1.2.3 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/critical/1/sipSPIOutgoingCallSDP: Failure in creating outbound streams SIP: (28231) Group (a= group line) attribute, level 65535 instance 1 not found. Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 12.1.2.3 for SIP Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 12.1.2.3 for SIP Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 12.1.2.3 Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 12.1.2.3 Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 19606 for stream 1 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/1/sipSPIDoBearerCapToCodecMapping: Bearer capability to Codec Mapping: DISABLED
Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Media/sipSPIAddSDPMediaPayload: Preferred method of dtmf relay is: 6, with payload: 101 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/131074/sipSPIBwCacCalcMaxAudioBandwidth: calculating max bw from preffered codecs (local offer) SIP: (28231) Group (a= group line) attribute, level 65535 instance 1 not found. Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/131074/sipSPIBwCacCalcMaxAudioBandwidth: max bw (excluding pak overhead) from preffered codecs: codec g711ulaw bw 64000 index 0 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/critical/2/sipSPIBwCacCalcMaxAudioBandwidth: audio caps channel idx not found !!!! Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/131074/sipSPIBwCacCalcMaxAudioBandwidth: max bw (including pak overhead) from preffered codecs: codec g711ulaw bw 80000 Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20 Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/notify/8193/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/1/sipSPIOutgoingCallSDP: Creating recv-only stream for outbound call Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Media/sipSPIProcessRtpSessions: Processing stream state = STREAM_IDLE Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Media/sipSPIProcessRtpSessions: No active streams. Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/131072/sipSPIBwCacUpdateAccountedBw: bwcac update accounted BW Option 5 flow mode flow-through audio bw 80000 bps video bw 0 bps fax bw 0 bps total bw 80000 bps accounted bw 0 bps Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/139264/sipSPIBwCacUpdateInterfaceBw: NOP (no interface change) Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/131072/sipSPIBwCacUpdateAccountedBw: bwcac update accounted bw (no interface change) Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 66.147.235.3,Port 5060, Transport 1, SentBy Port 5060 Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x245391FC with refCount = 1 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:0, container:2F93A130 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/8192/Session-Timer/sipSTSLSRReqSend: Session timer is not required Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/8192/Session-Timer/sipSTSLMain: SE: 0;refresher:none peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:1800, Configured Min-SE:1800 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 0 event Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/notify/4096/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/notify/4096/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_offer_ans_handle_sent_sdp: Feb 19 20:19:34.182: //28231/EB59E1D3B413/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_SENT Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_offer_ans_is_invite_offer_valid: TRUE Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_offer_ans_common_offer_sent_hdlr: Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_iwf_handle_network_event: Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sccp_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_SENT_SDP Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/4096/is_sent_sccp_do_video_inactive: Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/4096/is_mode_sip_sccp_do_video: Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/4096/is_mode_sip_sccp_do_video: Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/4096/sip_iwf_def_ed_sent_sdp_offer_hdlr: Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:S_SIP_IWF_SDP_SENT_AWAIT_SDP Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_EARLY_DIALOG_OFFER_SENT Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/info/2048/sipSPIgetRegistrarHost: registrar host retrieved : bumblebee.vtnoc.net Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/critical/4096/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not a Forked leg.. Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/critical/1024/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added. SIP: (28231) Group (a= group line) attribute, level 65535 instance 1 not found. Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/34816/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/4096/sipSPISendInvite: Associated container=0x2F93A130 to Invite Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 277 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: msg=0x245391FC, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x4F5026C Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x2B6BA190 with connection=0x24D9EACC context list Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x245391FC Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x245391FC, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/512/sentInviteRequest: Sent Invite in state STATE_IDLE Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sentInviteRequest: Transaction active. Facilities will be queued. Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/State/sipSPIChangeState: 0x2B6BA190 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_SENT_INVITE, SUBSTATE_NONE) Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Media/sipSPIProcessRtpSessions: Processing stream state = STREAM_ADDING Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/verbose/6/sipSPIAddStream: set stream_callid from ccb->ccCallID:0x6E47, media_type:0 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 28231) to the VOIP RTP library Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 12.1.2.3 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/1/sipSPIAssignStreamCallId: Assigning streamid 28231 to stream 1. Old streamid = 28231 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/8192/sipSPIUpdateRtcpSession: ccb->flags != LOOPBACK Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Media/sipSPIUpdateRtcpSession: Setting do_rtcp = FALSE 0 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info laddr = 12.1.2.3, lport = 19606, raddr = 0.0.0.0, rport=0, do_rtcp=FALSE src_callid = 28231, dest_callid = -1, stream type = voice+dtmf, stream direction = SENDRECV media_ip_addr = - , vrf tableid = 0 media_addr_type = 1negotiated_bandwidth (kbps) = 0 srtp_services = 0 nat_flag = 0 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/verbose/1/sipSPICreateRtpSession: sess: 220713D4 do_rtcp:0 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Media/sipSPICreateRtpSession: stun is disabled Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/critical/131072/sipSPIUpdateRtcpSession: Not able to Associate DSCP Profile with GCCB dscp_policy = 0x0, IS_SIPSPI_MODE_IN_SIP_SIP = 0 dscpPolicySeviceBlock = 0x0 , stream->qos_info = 0x0 Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIUpdateRtcpSession: Voice quality monitoring is not enabled for this RTP session due to sdp passthru enabled Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIUpdateRtcpSession: VQM: gccb=0x0, gccb->callId=0, ccb->ccCallID=28231 Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/notify/2080/sipSPIUpdateRtcpSession: DTMF inb/oob disabled Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/State/sipSPIChangeStreamState: Stream (callid = 28231) State changed from (STREAM_ADDING) to (STREAM_ACTIVE) Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Info/info/2/sipSPIUpdateCallEntry: Call 28231 set InfoType to SPEECH Feb 19 20:19:34.182: //-1/xxxxxxxxxxxx/SIP/Error/httpish_msg_free: Freeing NULL pointer! Feb 19 20:19:34.182: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Sent: INVITE sip:18662966457@bumblebee.vtnoc.net:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK798C11E1 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:18662966457@bumblebee.vtnoc.net> Date: Fri, 19 Feb 2016 20:19:34 GMT Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 Supported: 100rel,timer,resource-priority,replaces,sdp-anat Min-SE: 1800 Cisco-Guid: 3948536275-3598455269-3021200718-1106222154 User-Agent: Cisco-SIPGateway/IOS-15.3.3.M6 All Feb 19 20:19:34.332: //28231/EB59E1D3B413/SIP/Info/verbose/1024/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX Feb 19 20:19:34.332: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x2760FB28) counter, current msg->refCount = 1 Feb 19 20:19:34.332: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2760FB28 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToTable: Added context(0x2B6A0A10) with key=[23215] to table Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_service_init: Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_service_init: Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_forking_init: MF: Queue is initialised.. Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/notify/262144/ccsipRegisterSetTargetInfo: p2p mode with Registrar Server = dns:bumblebee.vtnoc.net Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/262144/ccsipRegisterSetTargetInfo: Parsing The Registrar Address Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/5120/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : bumblebee.vtnoc.net target_port : 5060
Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/5120/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/critical/8192/sipSPIOutboundProxyReuse: Do not reuse Outbound Proxy IP adress and Port Feb 19 20:19:35.886: //-1/000000000000/SIP/State/sipSPIChangeState: 0x2B6A0A10 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/6144/ccsip_spi_registrar_add_expires_header: Inside ccsip_spi_registrar_add_expires_header for Expires Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_OUTBOUND_REGISTER Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/262144/sipSPIIncrementOverloadCount: Local 1 Global 1 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToTable: Added context(0x2B6C6D50) with key=[23216] to table Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_service_init: Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_service_init: Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_forking_init: MF: Queue is initialised.. Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/notify/262144/ccsipRegisterSetTargetInfo: p2p mode with Registrar Server = dns:bumblebee.vtnoc.net Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/262144/ccsipRegisterSetTargetInfo: Parsing The Registrar Address Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/5120/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : bumblebee.vtnoc.net target_port : 5060
Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/5120/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/critical/8192/sipSPIOutboundProxyReuse: Do not reuse Outbound Proxy IP adress and Port Feb 19 20:19:35.886: //-1/000000000000/SIP/State/sipSPIChangeState: 0x2B6C6D50 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/6144/ccsip_spi_registrar_add_expires_header: Inside ccsip_spi_registrar_add_expires_header for Expires Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_OUTBOUND_REGISTER Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/262144/sipSPIIncrementOverloadCount: Local 1 Global 2 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToTable: Added context(0x2B6AD5D0) with key=[23217] to table Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_service_init: Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_service_init: Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_forking_init: MF: Queue is initialised.. Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/notify/262144/ccsipRegisterSetTargetInfo: p2p mode with Registrar Server = dns:bumblebee.vtnoc.net Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/262144/ccsipRegisterSetTargetInfo: Parsing The Registrar Address Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/5120/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : bumblebee.vtnoc.net target_port : 5060
Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/5120/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/critical/8192/sipSPIOutboundProxyReuse: Do not reuse Outbound Proxy IP adress and Port Feb 19 20:19:35.886: //-1/000000000000/SIP/State/sipSPIChangeState: 0x2B6AD5D0 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/6144/ccsip_spi_registrar_add_expires_header: Inside ccsip_spi_registrar_add_expires_header for Expires Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_OUTBOUND_REGISTER Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/262144/sipSPIIncrementOverloadCount: Local 1 Global 3 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 40 Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/262144/act_idle_outgoing_register: In act_idle_outgoing_register
Feb 19 20:19:35.886: //28232/000000000000/SIP/Info/info/262144/act_idle_outgoing_register: Send REGISTER to bumblebee.vtnoc.net:5060
Feb 19 20:19:35.886: //28232/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToUACTable: ****Adding to UAC table.0x2B6A0A10 4DC50FFD-D67211E5-B373DD4E-41EF9C4A Feb 19 20:19:35.886: //28232/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to table. ccb=0x2B6A0A10 key=4DC50FFD-D67211E5-B373DD4E-41EF9C4A balance 0 Feb 19 20:19:35.886: //28232/000000000000/SIP/Info/info/262144/act_idle_outgoing_register: Locally Resolved IP:66.147.235.3:5060 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 12.1.2.3 for SIP Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 12.1.2.3 for SIP Feb 19 20:19:35.886: //28232/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 12.1.2.3 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 12.1.2.3 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x27321740 with refCount = 1 Feb 19 20:19:35.886: //28232/000000000000/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 7 event Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT Feb 19 20:19:35.886: //28232/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:35.886: //28232/000000000000/SIP/Info/info/4096/sipSPISendRegister: Associated container=0x2F939688 to Register Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:19:35.886: //28232/000000000000/SIP/Transport/sipSPISendRegister: Sending REGISTER to the transport layer Feb 19 20:19:35.886: //28232/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:19:35.886: //28232/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x27321740, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x4F4EA94 Feb 19 20:19:35.886: //28232/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:35.886: //28232/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x2B6A0A10 with connection=0x24D9EACC context list Feb 19 20:19:35.886: //28232/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x27321740 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x27321740, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:19:35.886: //28232/000000000000/SIP/State/sipSPIChangeState: 0x2B6A0A10 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) Feb 19 20:19:35.886: //28232/000000000000/SIP/State/sipSPIChangeState: 0x2B6A0A10 : State change from (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 40 Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/262144/act_idle_outgoing_register: In act_idle_outgoing_register
Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/262144/act_idle_outgoing_register: Send REGISTER to bumblebee.vtnoc.net:5060
Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToUACTable: ****Adding to UAC table.0x2B6C6D50 4DC50FFD-D67211E5-B377DD4E-41EF9C4A Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to table. ccb=0x2B6C6D50 key=4DC50FFD-D67211E5-B377DD4E-41EF9C4A balance 1 Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/262144/act_idle_outgoing_register: Locally Resolved IP:66.147.235.3:5060 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 12.1.2.3 for SIP Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 12.1.2.3 for SIP Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 12.1.2.3 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 12.1.2.3 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2118DDB0 with refCount = 1 Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 7 event Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/4096/sipSPISendRegister: Associated container=0x2F938558 to Register Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:19:35.886: //-1/000000000000/SIP/Transport/sipSPISendRegister: Sending REGISTER to the transport layer Feb 19 20:19:35.886: //-1/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:19:35.886: //-1/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x2118DDB0, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x4F4EA94 Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:35.886: //-1/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x2B6C6D50 with connection=0x24D9EACC context list Feb 19 20:19:35.886: //-1/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2118DDB0 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2118DDB0, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:19:35.886: //-1/000000000000/SIP/State/sipSPIChangeState: 0x2B6C6D50 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) Feb 19 20:19:35.886: //-1/000000000000/SIP/State/sipSPIChangeState: 0x2B6C6D50 : State change from (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 40 Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/262144/act_idle_outgoing_register: In act_idle_outgoing_register
Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/262144/act_idle_outgoing_register: Send REGISTER to bumblebee.vtnoc.net:5060
Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToUACTable: ****Adding to UAC table.0x2B6AD5D0 4DC50FFD-D67211E5-B379DD4E-41EF9C4A Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to table. ccb=0x2B6AD5D0 key=4DC50FFD-D67211E5-B379DD4E-41EF9C4A balance 0 Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/262144/act_idle_outgoing_register: Locally Resolved IP:66.147.235.3:5060 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 12.1.2.3 for SIP Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 12.1.2.3 for SIP Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 12.1.2.3 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 12.1.2.3 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x24CCC698 with refCount = 1 Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 7 event Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/4096/sipSPISendRegister: Associated container=0x2F938818 to Register Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:19:35.886: //-1/000000000000/SIP/Transport/sipSPISendRegister: Sending REGISTER to the transport layer Feb 19 20:19:35.886: //-1/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:19:35.886: //-1/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x24CCC698, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x4F4EA94 Feb 19 20:19:35.886: //-1/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:35.886: //-1/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x2B6AD5D0 with connection=0x24D9EACC context list Feb 19 20:19:35.886: //-1/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x24CCC698 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x24CCC698, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:19:35.886: //-1/000000000000/SIP/State/sipSPIChangeState: 0x2B6AD5D0 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) Feb 19 20:19:35.886: //-1/000000000000/SIP/State/sipSPIChangeState: 0x2B6AD5D0 : State change from (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Sent: REGISTER sip:bumblebee.vtnoc.net:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK798E110F From: <sip:2001@bumblebee.vtnoc.net>;tag=B8F1AC9C-1898 To: <sip:2001@bumblebee.vtnoc.net> Date: Fri, 19 Feb 2016 20:19:35 GMT Call-ID: 4DC50FFD-D67211E5-B373DD4E-41EF9C4A User-Agent: Cisco-SIPGateway/IOS-15.3.3.M6 Max-Forwards: 70 Timestamp: 1455913175 CSeq: 40 REGISTER Contact: <sip:2001@12.1.2.3:5060> Expires: 300 Supported: path Content-Length: 0
Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x27321740 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Sent: REGISTER sip:bumblebee.vtnoc.net:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK798F111F From: <sip:2005@bumblebee.vtnoc.net>;tag=B8F1AC9C-67 To: <sip:2005@bumblebee.vtnoc.net> Date: Fri, 19 Feb 2016 20:19:35 GMT Call-ID: 4DC50FFD-D67211E5-B377DD4E-41EF9C4A User-Agent: Cisco-SIPGateway/IOS-15.3.3.M6 Max-Forwards: 70 Timestamp: 1455913175 CSeq: 40 REGISTER Contact: <sip:2005@12.1.2.3:5060> Expires: 300 Supported: path Content-Length: 0
Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2118DDB0 Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Sent: REGISTER sip:bumblebee.vtnoc.net:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK799072 From: <sip:2009@bumblebee.vtnoc.net>;tag=B8F1AC9C-F9C To: <sip:2009@bumblebee.vtnoc.net> Date: Fri, 19 Feb 2016 20:19:35 GMT Call-ID: 4DC50FFD-D67211E5-B379DD4E-41EF9C4A User-Agent: Cisco-SIPGateway/IOS-15.3.3.M6 Max-Forwards: 70 Timestamp: 1455913175 CSeq: 40 REGISTER Contact: <sip:2009@12.1.2.3:5060> Expires: 300 Supported: path Content-Length: 0
Feb 19 20:19:35.886: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x24CCC698 Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToTable: Added context(0x2B69A430) with key=[23218] to table Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_service_init: Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_service_init: Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_forking_init: MF: Queue is initialised.. Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/notify/262144/ccsipRegisterSetTargetInfo: p2p mode with Registrar Server = dns:bumblebee.vtnoc.net Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/verbose/262144/ccsipRegisterSetTargetInfo: Parsing The Registrar Address Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/verbose/5120/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : bumblebee.vtnoc.net target_port : 5060
Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/verbose/5120/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/critical/8192/sipSPIOutboundProxyReuse: Do not reuse Outbound Proxy IP adress and Port Feb 19 20:19:35.890: //-1/000000000000/SIP/State/sipSPIChangeState: 0x2B69A430 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/verbose/6144/ccsip_spi_registrar_add_expires_header: Inside ccsip_spi_registrar_add_expires_header for Expires Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_OUTBOUND_REGISTER Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/info/262144/sipSPIIncrementOverloadCount: Local 1 Global 4 Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToTable: Added context(0x2B6B3BB0) with key=[23219] to table Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_service_init: Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_service_init: Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_forking_init: MF: Queue is initialised.. Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/notify/262144/ccsipRegisterSetTargetInfo: p2p mode with Registrar Server = dns:bumblebee.vtnoc.net Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/verbose/262144/ccsipRegisterSetTargetInfo: Parsing The Registrar Address Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/verbose/5120/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : bumblebee.vtnoc.net target_port : 5060
Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/verbose/5120/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/critical/8192/sipSPIOutboundProxyReuse: Do not reuse Outbound Proxy IP adress and Port Feb 19 20:19:35.890: //-1/000000000000/SIP/State/sipSPIChangeState: 0x2B6B3BB0 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/verbose/6144/ccsip_spi_registrar_add_expires_header: Inside ccsip_spi_registrar_add_expires_header for Expires Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_OUTBOUND_REGISTER Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/info/262144/sipSPIIncrementOverloadCount: Local 1 Global 5 Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 40 Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/verbose/262144/act_idle_outgoing_register: In act_idle_outgoing_register
Feb 19 20:19:35.890: //28235/000000000000/SIP/Info/info/262144/act_idle_outgoing_register: Send REGISTER to bumblebee.vtnoc.net:5060
Feb 19 20:19:35.890: //28235/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToUACTable: ****Adding to UAC table.0x2B69A430 4DC50FFD-D67211E5-B374DD4E-41EF9C4A Feb 19 20:19:35.890: //28235/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to table. ccb=0x2B69A430 key=4DC50FFD-D67211E5-B374DD4E-41EF9C4A balance 0 Feb 19 20:19:35.890: //28235/000000000000/SIP/Info/info/262144/act_idle_outgoing_register: Locally Resolved IP:66.147.235.3:5060 Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 12.1.2.3 for SIP Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 12.1.2.3 for SIP Feb 19 20:19:35.890: //28235/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 12.1.2.3 Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 12.1.2.3 Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x232E2520 with refCount = 1 Feb 19 20:19:35.890: //28235/000000000000/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 7 event Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT Feb 19 20:19:35.890: //28235/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:35.890: //28235/000000000000/SIP/Info/info/4096/sipSPISendRegister: Associated container=0x2F9399A0 to Register Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:19:35.890: //28235/000000000000/SIP/Transport/sipSPISendRegister: Sending REGISTER to the transport layer Feb 19 20:19:35.890: //28235/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:19:35.890: //28235/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x232E2520, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x4F4EA94 Feb 19 20:19:35.890: //28235/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:35.890: //28235/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x2B69A430 with connection=0x24D9EACC context list Feb 19 20:19:35.890: //28235/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x232E2520 Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x232E2520, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:19:35.890: //28235/000000000000/SIP/State/sipSPIChangeState: 0x2B69A430 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) Feb 19 20:19:35.890: //28235/000000000000/SIP/State/sipSPIChangeState: 0x2B69A430 : State change from (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE) Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 40 Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/verbose/262144/act_idle_outgoing_register: In act_idle_outgoing_register
Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/info/262144/act_idle_outgoing_register: Send REGISTER to bumblebee.vtnoc.net:5060
Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToUACTable: ****Adding to UAC table.0x2B6B3BB0 4DC50FFD-D67211E5-B378DD4E-41EF9C4A Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to table. ccb=0x2B6B3BB0 key=4DC50FFD-D67211E5-B378DD4E-41EF9C4A balance 1 Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/info/262144/act_idle_outgoing_register: Locally Resolved IP:66.147.235.3:5060 Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 12.1.2.3 for SIP Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 12.1.2.3 for SIP Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 12.1.2.3 Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 12.1.2.3 Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2118DDB0 with refCount = 1 Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 7 event Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:35.890: //-1/000000000000/SIP/Info/info/4096/sipSPISendRegister: Associated container=0x2F937ED0 to Register Feb 19 20:19:35.890: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:19:35.890: //-1/000000000000/SIP/Transport/sipSPISendRegister: Sending REGISTER to the transport layer Feb 19 20:19:35.890: //-1/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE,uri="sip:bumblebee.vtnoc.net:5060",response="1faa69f467f50792d76a833078f10fa4",nonce="56c778f600003b0f017bc5bccb960caee1df4808c51e78e6",cnonce="82E89FBA",qop=auth,algorithm=md5,nc=00000001 Content-Length: 0
Feb 19 20:19:35.962: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x232E2520 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x232E2520 with refCount = 1 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x204E3B74 with refCount = 1 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [66.147.235.3]:5060, local_address:[12.1.2.3] Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x232E2520 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2498648C Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connid=4, transport=UDP Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/4608/sipHolderGetConnInstance: Return existing connection for port 5060 connId 4 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_get_method_from_request: Unable to extract request line from message Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog Feb 19 20:19:36.022: //-1/000000000000/SIP/Info/info/1024/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK799710E5 from via branch list Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x204E3B74) counter, current msg->refCount = 2 Feb 19 20:19:36.022: //-1/000000000000/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 200 OK Via: SIP/2.0/UDP 12.1.2.3:5060;received=12.1.2.3;rport=62497;branch=z9hG4bK799710E5 From: <sip:2005@bumblebee.vtnoc.net>;tag=B8F1AC9C-67 To: <sip:2005@bumblebee.vtnoc.net>;tag=8324aa8d99b6bc7e21f3eb535a640969.1014 Call-ID: 4DC50FFD-D67211E5-B377DD4E-41EF9C4A CSeq: 41 REGISTER Contact: <sip:2005@12.1.2.3:5060>;expires=300;received="sip:12.1.2.3:62497" Server: OpenSIPS (1.8.3-tls (x86_64/linux)) Content-Length: 0 Warning: 392 66.147.235.3:5060 "Noisy feedback tells: pid=31738 req_src_ip=12.1.2.3 req_src_port=62497 in_uri=sip:bumblebee.vtnoc.net:5060 out_uri=sip:bumblebee.vtnoc.net:5060 via_cnt==1"
Feb 19 20:19:36.022: //-1/000000000000/SIP/Info/verbose/1024/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/262144/sipSPIDecrementOverloadCount: Count:Local 0 Global 6 Feb 19 20:19:36.022: //-1/000000000000/SIP/Info/notify/262144/sipSPIRegPthruProcessResponse: Processing response w/ resp code == 200 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/verbose/262144/sipSPIGetRPCBFromRCB: Retreiving RCB [0x2B825288] from RPCB [0x0] Feb 19 20:19:36.022: //-1/000000000000/SIP/Info/critical/262144/sipSPIRegPthruProcessResponse: Error NO RPCB
Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/2048/ccsipRegisterStartRCBTimer: Starting timer for pattern 2005 for 240 seconds Feb 19 20:19:36.022: //-1/000000000000/SIP/Info/notify/1024/ccsip_gw_register_process_response: No P-Assoicated-URI present in Register Response Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x204E3B74) counter, current msg->refCount = 1 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIDeleteContextFromTable: Context for key=[23216] removed. Feb 19 20:19:36.022: //-1/000000000000/SIP/Info/verbose/4096/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x2B6C6D50 key=4DC50FFD-D67211E5-B377DD4E-41EF9C4A Feb 19 20:19:36.022: //-1/000000000000/SIP/Info/verbose/4096/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, unregistering context=0x2B6C6D50 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstancePurgeContextInConnection: Purging context gcb=0x2B6C6D50 from the connection=0x24D9EACC context list Feb 19 20:19:36.022: //-1/000000000000/SIP/Info/verbose/1/sipSPI_ipip_free_codec_profile: Codec Profiles Freed Feb 19 20:19:36.022: //-1/000000000000/SIP/Info/info/8192/sipSPIStopOverlapInfoTimer: Stopping Overlap Info Timer Feb 19 20:19:36.022: //28233/000000000000/SIP/Info/verbose/4096/sipSPIUfreeOneCCB: Freeing ccb 0x2B6C6D50 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIGetContextFromTable: NO context for key[23216] Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x204E3B74 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x245391FC with refCount = 1 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x232E2520 with refCount = 1 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [66.147.235.3]:5060, local_address:[12.1.2.3] Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x245391FC Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2498648C Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connid=4, transport=UDP Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/4608/sipHolderGetConnInstance: Return existing connection for port 5060 connId 4 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_get_method_from_request: Unable to extract request line from message Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog Feb 19 20:19:36.022: //28232/000000000000/SIP/Info/info/1024/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK799521ED from via branch list Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x232E2520) counter, current msg->refCount = 2 Feb 19 20:19:36.022: //28232/000000000000/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 200 OK Via: SIP/2.0/UDP 12.1.2.3:5060;received=12.1.2.3;rport=62497;branch=z9hG4bK799521ED From: <sip:2001@bumblebee.vtnoc.net>;tag=B8F1AC9C-1898 To: <sip:2001@bumblebee.vtnoc.net>;tag=8324aa8d99b6bc7e21f3eb535a640969.69a4 Call-ID: 4DC50FFD-D67211E5-B373DD4E-41EF9C4A CSeq: 41 REGISTER Contact: <sip:2001@12.1.2.3:5060>;expires=300;received="sip:12.1.2.3:62497" Server: OpenSIPS (1.8.3-tls (x86_64/linux)) Content-Length: 0 Warning: 392 66.147.235.3:5060 "Noisy feedback tells: pid=31748 req_src_ip=12.1.2.3 req_src_port=62497 in_uri=sip:bumblebee.vtnoc.net:5060 out_uri=sip:bumblebee.vtnoc.net:5060 via_cnt==1"
Feb 19 20:19:36.022: //28232/000000000000/SIP/Info/verbose/1024/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/262144/sipSPIDecrementOverloadCount: Count:Local 0 Global 5 Feb 19 20:19:36.022: //28232/000000000000/SIP/Info/notify/262144/sipSPIRegPthruProcessResponse: Processing response w/ resp code == 200 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/verbose/262144/sipSPIGetRPCBFromRCB: Retreiving RCB [0x2B8235C0] from RPCB [0x0] Feb 19 20:19:36.022: //28232/000000000000/SIP/Info/critical/262144/sipSPIRegPthruProcessResponse: Error NO RPCB
Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/2048/ccsipRegisterStartRCBTimer: Starting timer for pattern 2001 for 240 seconds Feb 19 20:19:36.022: //28232/000000000000/SIP/Info/notify/1024/ccsip_gw_register_process_response: No P-Assoicated-URI present in Register Response Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x232E2520) counter, current msg->refCount = 1 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIDeleteContextFromTable: Context for key=[23215] removed. Feb 19 20:19:36.022: //28232/000000000000/SIP/Info/verbose/4096/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x2B6A0A10 key=4DC50FFD-D67211E5-B373DD4E-41EF9C4A Feb 19 20:19:36.022: //28232/000000000000/SIP/Info/verbose/4096/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, unregistering context=0x2B6A0A10 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstancePurgeContextInConnection: Purging context gcb=0x2B6A0A10 from the connection=0x24D9EACC context list Feb 19 20:19:36.022: //28232/000000000000/SIP/Info/verbose/1/sipSPI_ipip_free_codec_profile: Codec Profiles Freed Feb 19 20:19:36.022: //28232/000000000000/SIP/Info/info/8192/sipSPIStopOverlapInfoTimer: Stopping Overlap Info Timer Feb 19 20:19:36.022: //28232/000000000000/SIP/Info/verbose/4096/sipSPIUfreeOneCCB: Freeing ccb 0x2B6A0A10 Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIGetContextFromTable: NO context for key[23215] Feb 19 20:19:36.022: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x232E2520 Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2760FB28 with refCount = 1 Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x245391FC with refCount = 1 Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [66.147.235.3]:5060, local_address:[12.1.2.3] Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2760FB28 Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2498648C Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connid=4, transport=UDP Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/4608/sipHolderGetConnInstance: Return existing connection for port 5060 connId 4 Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_get_method_from_request: Unable to extract request line from message Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog Feb 19 20:19:36.026: //28235/000000000000/SIP/Info/info/1024/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK79981D51 from via branch list Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x245391FC) counter, current msg->refCount = 2 Feb 19 20:19:36.026: //28235/000000000000/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 200 OK Via: SIP/2.0/UDP 12.1.2.3:5060;received=12.1.2.3;rport=62497;branch=z9hG4bK79981D51 From: <sip:2002@bumblebee.vtnoc.net>;tag=B8F1ACA0-30F To: <sip:2002@bumblebee.vtnoc.net>;tag=8324aa8d99b6bc7e21f3eb535a640969.4ae7 Call-ID: 4DC50FFD-D67211E5-B374DD4E-41EF9C4A CSeq: 41 REGISTER Contact: <sip:2002@12.1.2.3:5060>;expires=300;received="sip:12.1.2.3:62497" Server: OpenSIPS (1.8.3-tls (x86_64/linux)) Content-Length: 0 Warning: 392 66.147.235.3:5060 "Noisy feedback tells: pid=31758 req_src_ip=12.1.2.3 req_src_port=62497 in_uri=sip:bumblebee.vtnoc.net:5060 out_uri=sip:bumblebee.vtnoc.net:5060 via_cnt==1"
Feb 19 20:19:36.026: //28235/000000000000/SIP/Info/verbose/1024/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/262144/sipSPIDecrementOverloadCount: Count:Local 0 Global 4 Feb 19 20:19:36.026: //28235/000000000000/SIP/Info/notify/262144/sipSPIRegPthruProcessResponse: Processing response w/ resp code == 200 Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/verbose/262144/sipSPIGetRPCBFromRCB: Retreiving RCB [0x276181E0] from RPCB [0x0] Feb 19 20:19:36.026: //28235/000000000000/SIP/Info/critical/262144/sipSPIRegPthruProcessResponse: Error NO RPCB
Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/2048/ccsipRegisterStartRCBTimer: Starting timer for pattern 2002 for 240 seconds Feb 19 20:19:36.026: //28235/000000000000/SIP/Info/notify/1024/ccsip_gw_register_process_response: No P-Assoicated-URI present in Register Response Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x245391FC) counter, current msg->refCount = 1 Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIDeleteContextFromTable: Context for key=[23218] removed. Feb 19 20:19:36.026: //28235/000000000000/SIP/Info/verbose/4096/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x2B69A430 key=4DC50FFD-D67211E5-B374DD4E-41EF9C4A Feb 19 20:19:36.026: //28235/000000000000/SIP/Info/verbose/4096/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, unregistering context=0x2B69A430 Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstancePurgeContextInConnection: Purging context gcb=0x2B69A430 from the connection=0x24D9EACC context list Feb 19 20:19:36.026: //28235/000000000000/SIP/Info/verbose/1/sipSPI_ipip_free_codec_profile: Codec Profiles Freed Feb 19 20:19:36.026: //28235/000000000000/SIP/Info/info/8192/sipSPIStopOverlapInfoTimer: Stopping Overlap Info Timer Feb 19 20:19:36.026: //28235/000000000000/SIP/Info/verbose/4096/sipSPIUfreeOneCCB: Freeing ccb 0x2B69A430 Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIGetContextFromTable: NO context for key[23218] Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x245391FC Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x245391FC with refCount = 1 Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x24CCC698 with refCount = 1 Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [66.147.235.3]:5060, local_address:[12.1.2.3] Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x245391FC Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2498648C Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connid=4, transport=UDP Feb 19 20:19:36.026: //-1/xxxxxxxxxxxx/SIP/Info/info/4608/sipHolderGetConnInstance: Return existing connection for port 5060 connId 4 Feb 19 20:19:36.028: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2FC5EE44 Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2FC5EE44 with refCount = 1 Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2118DDB0 with refCount = 1 Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [66.147.235.3]:5060, local_address:[12.1.2.3] Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2FC5EE44 Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2498648C Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connid=4, transport=UDP Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/4608/sipHolderGetConnInstance: Return existing connection for port 5060 connId 4 Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_get_method_from_request: Unable to extract request line from message Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x2118DDB0) counter, current msg->refCount = 2 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 12.1.2.3:5060;rport=62497;received=12.1.2.3;branch=z9hG4bK798DDA8 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:+18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 102 INVITE Record-Route: <sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Record-Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136> Contact: <sip:+18662966457@4.55.23.33:5060> Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE Require: 100rel RSeq: 22423 Content-Length: 231 Content-Disposition: session; handling=required Content-Type: application/sdp v=0 o=Sonus_UAC 16186 28782 IN IP4 4.55.23.33 s=SIP Media Capabilities c=IN IP4 4.55.23.6 t=0 0 m=audio 19896 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=maxptime:20
Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/1024/sipSPICheckResponseExt: Got new RR header Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/1024/sipSPICheckResponseExt: This is first RR in this dialog Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/critical/4096/sipSPICheckReliableProvStringtag: Unable to access supported header values Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentGTD: No GTD found in inbound container Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/1/sipSPIDoMediaNegotiation: Number of m-lines = 1 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/1/sipSPIValidateConnectionAddress: Dest port = 19896 SIP: Attribute mid, level 1 instance 1 not found. Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 12.1.2.3 Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec No Codec Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96 Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/critical/1/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved as its in use by other codec Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/critical/1/sipSPIUpdateDynamicPT: Requested payload-Type (101) is reserved by another application Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101 Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec: Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/1/sipSPIDoAudioNegotiation: Codec (g711ulaw) Negotiation Successful on Static Payload for m-line 1 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/1/sipSPIDoPtimeNegotiation: No ptime present or multiple ptime attributes that can't be handled Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/8/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/1/sipSPIDoDTMFRelayNegotiation: m-line index 1 Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/1/sipSPIReserveRtpNtePayload: Reserved the payload type 101 for RTP-NTE Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/32/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/1/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events. Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/8209/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/critical/8193/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/1/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/1/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1 payload_type=0, codec_bytes=160, codec=g711ulaw, dtmf_relay=rtp-nte stream_type=voice+dtmf (1), dest_ip_address=4.55.23.6, dest_port=19896 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING) Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/131073/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/131072/sipSPIDoStreamQoSNegotiation: Best effort Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_iwf_handle_generic_event: Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sccp_early_dialog_container, cur_state:S_SIP_IWF_SDP_SENT_AWAIT_SDP, event:E_SIP_IWF_EV_CALL_BRIDGE Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_iwf_process_event: IWF - cnfsm ret 2 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPIUpdCallWithSdpInfo: Preferred Codec : g711ulaw, 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
Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 12.1.2.3 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_offer_ans_handle_rcvd_sdp: Feb 19 20:19:40.335: //28231/EB59E1D3B413/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 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_offer_ans_is_incoming_invite_resp_answer_valid: TRUE Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_offer_ans_common_answer_rcvd_hdlr: Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_iwf_handle_network_event: Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sccp_early_dialog_container, cur_state:S_SIP_IWF_SDP_SENT_AWAIT_SDP, event:E_SIP_IWF_EV_RCVD_SDP Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/sip_iwf_def_ed_rcvd_sdp_answer_hdlr: Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/131074/sipSPIBwCacCalcNegoAudioBandwidth: max audio bw (including pak overhead) from negotiated stream : codec g711ulaw bw 80000 bps index 1 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/131072/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 0 bps Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/131072/sipSPIBwCacUpdateInterfaceBw: bwcac updating interface BVI255 bw 80 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/131072/sipSPIBwCacUpdateAccountedBw: bwcac update accounted bw (initial answer) accounted bw adjusted to 80000 delta 80000 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:S_SIP_IWF_SDP_DONE Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_EARLY_DIALOG_OFFER_ANSWER_COMPLETE Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPIUpdCallWithSdpInfo: Stream type : voice+dtmf Media line : 1 State : STREAM_ADDING (2) Stream address type : 1 Callid : 28231 Negotiated Codec : g711ulaw, bytes :160 Nego. Codec payload : 0 (tx), 0 (rx) Negotiated DTMF relay : rtp-nte Negotiated NTE payload : 101 (tx), 101 (rx) Negotiated CN payload : 0 Media Srce Addr/Port : [12.1.2.3]:19606 Media Dest Addr/Port : [4.55.23.6]:19896
Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/critical/1024/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/133120/sipSPIBwCacIsDialPeerBwAvailable: bwcac NOP dial-peer bw available tag 13 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/1/sipSPIBwCacIsInterfaceBwAvailable: bwcac interface bw threshold not configured Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/131072/sipSPIBwCacVerifyBwThreshold: bwcac verify bw threshold, bw available allow call total bw 80000 bps Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentQSIG: No QSIG Body found in inbound container Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentQ931: No RawMsg Body found in inbound container Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/critical/12288/sipSPICreateNewRawMsg: No Data to form The Raw Message
Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/HandleSIP1xxSessionProgress: ccsip_api_call_cut_progress returned: SIP_SUCCESS Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/sipSPIChangeState: 0x2B6BA190 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) to (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x245391FC with refCount = 1 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 2 event Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/4096/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/4096/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/sipSPIAddRouteHeaders: status = TRUE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/4096/sipSPIGenerateAuthorizationResponse: HA1 is: 3c7356a2d9242d5bcca92572790352ff Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/sipSPISendPrack: Associated container=0x2F937C68 to Prack Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Transport/sipSPISendPrack: Sending PRACK to the transport layer Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: msg=0x245391FC, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x4F4F9F8 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x2B6BA190 is already on connection=0x24D9EACC context_list Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x245391FC Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x245391FC, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/512/sentPrack: Sent Prack Request, starting PrackTimer Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/sipSPIChangeState: 0x2B6BA190 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) to (STATE_RECD_PROCEEDING, SUBSTATE_NONE) Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/4096/HandleSIP1xxSessionProgress: Transaction active. Facilities will be queued. Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x2118DDB0) counter, current msg->refCount = 1 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_bridge: confID = 1104, srcCallID = 28231, dstCallID = 28230 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/1/sipSPIUupdateCcCallIds: Old src/dest ccCallids: -1/-1, new src/dest ccCallids: 28231/28230 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/1/sipSPIUupdateCcCallIds: Old streamcallid=28231, new streamcallid=28231 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_iwf_handle_generic_event: Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sccp_early_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_CALL_BRIDGE Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_iwf_process_event: IWF - cnfsm ret 2 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/256/ccsip_bridge: xcoder_attached = 0, xmitFunc = 0x4848172, ccb xmitFunc = 0x4848172 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/24576/ccsip_spi_check_call_locally_held: CCSIP: call is locally noton-hold Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPIProcessRtpSessions: Processing stream state = STREAM_ADDING Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/6/sipSPIAddStream: set stream_callid from ccb->ccCallID:0x6E47, media_type:0 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 28231) to the VOIP RTP library Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 12.1.2.3 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/1/sipSPIAssignStreamCallId: Assigning streamid 28231 to stream 1. Old streamid = 28231 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/8192/sipSPIUpdateRtcpSession: ccb->flags != LOOPBACK Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPIUpdateRtcpSession: setting do_rtcp= TRUE for non forked leg 1 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/1/is_call_held: Remote media IP addr: 4.55.23.6 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/1/is_call_held: Media IP Addr 4.55.23.6, RTCP Type 3 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info laddr = 12.1.2.3, lport = 19606, raddr = 4.55.23.6, rport=19896, do_rtcp=TRUE src_callid = 28231, dest_callid = 28230, stream type = voice+dtmf, stream direction = SENDRECV media_ip_addr = 4.55.23.6, vrf tableid = 0 media_addr_type = 1negotiated_bandwidth (kbps) = 0 srtp_services = 0 nat_flag = 0 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPIUpdateRtcpSession: RTP session already created - update Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:2FA7142C Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/critical/131072/sipSPIUpdateRtcpSession: Not able to Associate DSCP Profile with GCCB dscp_policy = 0x0, IS_SIPSPI_MODE_IN_SIP_SIP = 0 dscpPolicySeviceBlock = 0x0 , stream->qos_info = 0x0 Feb 19 20:19:40.335: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIUpdateRtcpSession: VQM: gccb=0x0, gccb->callId=0, ccb->ccCallID=28231 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/8193/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled. Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/2080/sipSPIUpdateRtcpSession: DTMF inb/oob iwf enabled 0 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/4097/sipSPI_ipip_is_escalation: local channels = 0, peer channels = 0 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPIGetNewLocalMediaDirection: New Remote Media Direction = SENDRECV Present Local Media Direction = SENDRECV New Local Media Direction = SENDRECV retVal = 0
Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/sipSPIChangeStreamState: Stream (callid = 28231) State changed from (STREAM_ADDING) to (STREAM_ACTIVE) Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/notify/32/ccsip_bridge: DTMF inb/oob iwf enabled 0 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_run_deferred_media_negotiate: Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_is_media_negotiate_app_trigger_reinvite_deferred: retVal : 0 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 3, Event Id: CC_EV_CALL_PING_DONE Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: IWF Event: E_SIP_IWF_EV_PEER_CAPS Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sccp_early_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_PEER_CAPS Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/is_mode_sip_sccp_do_video: Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/sip_iwf_def_peer_caps_ind_hdlr: Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/4097/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=28231, current_seq_num=0x1ABD Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/4097/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=28231, current_seq_num=0xD93 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/1/sip_iwf_def_process_caps_ind: Load DSP with negotiated codec: g711ulaw, Bytes=160 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/1/sip_iwf_def_process_caps_ind: Set forking flag to 0x0 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/32/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_NTE_AND_OOB with rx payload = 101, tx payload = 101 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/10241/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/12288/sipSPIGetModemInfoPerCall: peer_callID=28230 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/8193/sip_set_modem_caps: Disabling Modem Relay... Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/8193/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/8193/sip_set_modem_caps: Modem Relay & Passthru both disabled Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/8193/sip_set_modem_caps: nse payload = 0, ptru mode = 0, ptru-codec=0, redundancy=0, xid=0, relay=0, sprt-retry=12, latecncy=200, compres-dir=3, dict=1024, strnlen=32 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPISetStreamInfo: 1 Active Streams Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPISetStreamInfo: Adding stream type (voice+dtmf) from media line 1 codec g711ulaw Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPISetStreamInfo: caps.stream_count=1,caps.stream[0].stream_type=0x3, caps.stream_list.xmitFunc= Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPISetStreamInfo: voip_rtp_xmit, caps.stream_list.context= Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Media/sipSPISetStreamInfo: 0x2FB73330 (gccb) Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/1/sip_iwf_def_process_caps_ind: Load DSP with codec : g711ulaw, Bytes=160, payload = 0 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/1/sip_iwf_def_process_caps_ind: ccsip_caps_ind: ccb->pld.flags_ipip = 0x2201 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/1/sip_iwf_def_process_caps_ind: Calling cc_api_caps_ack() Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_ipip_media_service_get_event_data: Event id = 7 Feb 19 20:19:40.335: //28231/EB59E1D3B413/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 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_iwf_handle_peer_event: Return value: SIP_IWF_SUCCESS Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_iwf_map_cc_return_code: Mapping SIP_IWF_SUCCESS Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 3, Event Id: CC_EV_CALL_FEATURE Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: IWF Event: E_SIP_IWF_EV_PEER_CAPS_ACK, Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sccp_early_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_PEER_CAPS_ACK, Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/is_mode_sip_sccp: Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/sip_iwf_def_peer_caps_ack_hdlr: Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/8193/sip_iwf_tdm_process_caps_ack: Set forking flag to 0x0 Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_iwf_handle_peer_event: Return value: SIP_IWF_SUCCESS Feb 19 20:19:40.335: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_iwf_map_cc_return_code: Mapping SIP_IWF_SUCCESS Feb 19 20:19:40.337: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Sent: PRACK sip:+18662966457@4.55.23.33:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK799C19D1 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Date: Fri, 19 Feb 2016 20:19:34 GMT Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 103 PRACK RAck: 22423 102 INVITE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Allow-Events: telephone-event Proxy-Authorization: Digest username="17866462052",realm="bumblebee.vtnoc.net",uri="sip:+18662966457@4.55.23.33:5060",response="a64cb0c01ee0b2356de4f2cb186dbbda",nonce="56c778f400003ade2d1a1a773ec81adab2a27b7968305c47",cnonce="EE93A286",qop=auth,algorithm=md5,nc=00000002 Max-Forwards: 70 Content-Length: 0
Feb 19 20:19:40.337: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x245391FC Feb 19 20:19:40.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x245391FC with refCount = 1 Feb 19 20:19:40.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2760FB28 with refCount = 1 Feb 19 20:19:40.826: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [66.147.235.3]:5060, local_address:[12.1.2.3] Feb 19 20:19:40.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x245391FC Feb 19 20:19:40.826: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Feb 19 20:19:40.826: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2498648C Feb 19 20:19:40.826: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connid=4, transport=UDP Feb 19 20:19:40.826: //-1/xxxxxxxxxxxx/SIP/Info/info/4608/sipHolderGetConnInstance: Return existing connection for port 5060 connId 4 Feb 19 20:19:40.826: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_get_method_from_request: Unable to extract request line from message Feb 19 20:19:40.826: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog Feb 19 20:19:40.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x2760FB28) counter, current msg->refCount = 2 Feb 19 20:19:40.826: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 12.1.2.3:5060;rport=62497;received=12.1.2.3;branch=z9hG4bK798DDA8 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:+18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 102 INVITE Record-Route: <sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Record-Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136> Contact: <sip:+18662966457@4.55.23.33:5060> Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE Require: 100rel RSeq: 22423 Content-Length: 231 Content-Disposition: session; handling=required Content-Type: application/sdp v=0 o=Sonus_UAC 16186 28782 IN IP4 4.55.23.33 s=SIP Media Capabilities c=IN IP4 4.55.23.6 t=0 0 m=audio 19896 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=maxptime:20
Feb 19 20:19:40.826: //28231/EB59E1D3B413/SIP/Info/verbose/1024/sipSPICheckResponseExt: Got new RR header Feb 19 20:19:40.826: //28231/EB59E1D3B413/SIP/Info/notify/1024/HandleSIP1xxSessionProgress: Dropping 183 - Duplicate or Unexpected Feb 19 20:19:40.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x2760FB28) counter, current msg->refCount = 1 Feb 19 20:19:40.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2760FB28 Feb 19 20:19:40.836: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2760FB28 with refCount = 1 Feb 19 20:19:40.836: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/sipSPIAddRouteHeaders: status = TRUE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Feb 19 20:19:40.836: //28231/EB59E1D3B413/SIP/Info/info/4096/sipSPISendPrack: Associated container=0x2F937C68 to Prack Feb 19 20:19:40.836: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:19:40.836: //28231/EB59E1D3B413/SIP/Transport/sipSPISendPrack: Sending PRACK to the transport layer Feb 19 20:19:40.836: //28231/EB59E1D3B413/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:19:40.836: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: msg=0x2760FB28, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x0 Feb 19 20:19:40.836: //28231/EB59E1D3B413/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:40.836: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:19:40.836: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:19:40.836: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x2B6BA190 is already on connection=0x24D9EACC context_list Feb 19 20:19:40.836: //28231/EB59E1D3B413/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2760FB28 Feb 19 20:19:40.836: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2760FB28, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:19:40.836: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Sent: PRACK sip:+18662966457@4.55.23.33:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK799C19D1 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Date: Fri, 19 Feb 2016 20:19:34 GMT Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 103 PRACK RAck: 22423 102 INVITE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Allow-Events: telephone-event Proxy-Authorization: Digest username="17866462052",realm="bumblebee.vtnoc.net",uri="sip:+18662966457@4.55.23.33:5060",response="a64cb0c01ee0b2356de4f2cb186dbbda",nonce="56c778f400003ade2d1a1a773ec81adab2a27b7968305c47",cnonce="EE93A286",qop=auth,algorithm=md5,nc=00000002 Max-Forwards: 70 Content-Length: 0
Feb 19 20:19:40.836: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2760FB28 Feb 19 20:19:41.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2760FB28 with refCount = 1 Feb 19 20:19:41.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x245391FC with refCount = 1 Feb 19 20:19:41.826: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [66.147.235.3]:5060, local_address:[12.1.2.3] Feb 19 20:19:41.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2760FB28 Feb 19 20:19:41.826: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Feb 19 20:19:41.826: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2498648C Feb 19 20:19:41.826: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connid=4, transport=UDP Feb 19 20:19:41.826: //-1/xxxxxxxxxxxx/SIP/Info/info/4608/sipHolderGetConnInstance: Return existing connection for port 5060 connId 4 Feb 19 20:19:41.826: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_get_method_from_request: Unable to extract request line from message Feb 19 20:19:41.826: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog Feb 19 20:19:41.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x245391FC) counter, current msg->refCount = 2 Feb 19 20:19:41.826: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 12.1.2.3:5060;rport=62497;received=12.1.2.3;branch=z9hG4bK798DDA8 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:+18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 102 INVITE Record-Route: <sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Record-Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136> Contact: <sip:+18662966457@4.55.23.33:5060> Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE Require: 100rel RSeq: 22423 Content-Length: 231 Content-Disposition: session; handling=required Content-Type: application/sdp v=0 o=Sonus_UAC 16186 28782 IN IP4 4.55.23.33 s=SIP Media Capabilities c=IN IP4 4.55.23.6 t=0 0 m=audio 19896 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=maxptime:20
Feb 19 20:19:41.826: //28231/EB59E1D3B413/SIP/Info/verbose/1024/sipSPICheckResponseExt: Got new RR header Feb 19 20:19:41.826: //28231/EB59E1D3B413/SIP/Info/notify/1024/HandleSIP1xxSessionProgress: Dropping 183 - Duplicate or Unexpected Feb 19 20:19:41.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x245391FC) counter, current msg->refCount = 1 Feb 19 20:19:41.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x245391FC Feb 19 20:19:41.836: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x245391FC with refCount = 1 Feb 19 20:19:41.836: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/sipSPIAddRouteHeaders: status = TRUE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Feb 19 20:19:41.836: //28231/EB59E1D3B413/SIP/Info/info/4096/sipSPISendPrack: Associated container=0x2F937C68 to Prack Feb 19 20:19:41.836: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:19:41.836: //28231/EB59E1D3B413/SIP/Transport/sipSPISendPrack: Sending PRACK to the transport layer Feb 19 20:19:41.836: //28231/EB59E1D3B413/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:19:41.836: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: msg=0x245391FC, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x0 Feb 19 20:19:41.836: //28231/EB59E1D3B413/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:41.836: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:19:41.836: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:19:41.836: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x2B6BA190 is already on connection=0x24D9EACC context_list Feb 19 20:19:41.836: //28231/EB59E1D3B413/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x245391FC Feb 19 20:19:41.836: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x245391FC, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:19:41.836: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Sent: PRACK sip:+18662966457@4.55.23.33:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK799C19D1 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Date: Fri, 19 Feb 2016 20:19:34 GMT Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 103 PRACK RAck: 22423 102 INVITE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Allow-Events: telephone-event Proxy-Authorization: Digest username="17866462052",realm="bumblebee.vtnoc.net",uri="sip:+18662966457@4.55.23.33:5060",response="a64cb0c01ee0b2356de4f2cb186dbbda",nonce="56c778f400003ade2d1a1a773ec81adab2a27b7968305c47",cnonce="EE93A286",qop=auth,algorithm=md5,nc=00000002 Max-Forwards: 70 Content-Length: 0
Feb 19 20:19:41.836: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x245391FC Feb 19 20:19:43.506: //28231/EB59E1D3B413/SIP/Info/verbose/32768/ccsip_indicate_rt_packet_stats: Processing stats for callid=28231, proc_id=9 Feb 19 20:19:43.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x245391FC with refCount = 1 Feb 19 20:19:43.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2760FB28 with refCount = 1 Feb 19 20:19:43.826: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [66.147.235.3]:5060, local_address:[12.1.2.3] Feb 19 20:19:43.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x245391FC Feb 19 20:19:43.826: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Feb 19 20:19:43.826: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2498648C Feb 19 20:19:43.826: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connid=4, transport=UDP Feb 19 20:19:43.826: //-1/xxxxxxxxxxxx/SIP/Info/info/4608/sipHolderGetConnInstance: Return existing connection for port 5060 connId 4 Feb 19 20:19:43.826: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_get_method_from_request: Unable to extract request line from message Feb 19 20:19:43.826: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog Feb 19 20:19:43.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x2760FB28) counter, current msg->refCount = 2 Feb 19 20:19:43.826: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 12.1.2.3:5060;rport=62497;received=12.1.2.3;branch=z9hG4bK798DDA8 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:+18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 102 INVITE Record-Route: <sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Record-Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136> Contact: <sip:+18662966457@4.55.23.33:5060> Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE Require: 100rel RSeq: 22423 Content-Length: 231 Content-Disposition: session; handling=required Content-Type: application/sdp v=0 o=Sonus_UAC 16186 28782 IN IP4 4.55.23.33 s=SIP Media Capabilities c=IN IP4 4.55.23.6 t=0 0 m=audio 19896 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=maxptime:20
Feb 19 20:19:43.826: //28231/EB59E1D3B413/SIP/Info/verbose/1024/sipSPICheckResponseExt: Got new RR header Feb 19 20:19:43.826: //28231/EB59E1D3B413/SIP/Info/notify/1024/HandleSIP1xxSessionProgress: Dropping 183 - Duplicate or Unexpected Feb 19 20:19:43.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x2760FB28) counter, current msg->refCount = 1 Feb 19 20:19:43.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2760FB28 Feb 19 20:19:43.836: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2760FB28 with refCount = 1 Feb 19 20:19:43.836: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/sipSPIAddRouteHeaders: status = TRUE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Feb 19 20:19:43.836: //28231/EB59E1D3B413/SIP/Info/info/4096/sipSPISendPrack: Associated container=0x2F937C68 to Prack Feb 19 20:19:43.836: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:19:43.836: //28231/EB59E1D3B413/SIP/Transport/sipSPISendPrack: Sending PRACK to the transport layer Feb 19 20:19:43.836: //28231/EB59E1D3B413/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:19:43.836: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: msg=0x2760FB28, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x0 Feb 19 20:19:43.836: //28231/EB59E1D3B413/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:43.836: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:19:43.836: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:19:43.836: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x2B6BA190 is already on connection=0x24D9EACC context_list Feb 19 20:19:43.836: //28231/EB59E1D3B413/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2760FB28 Feb 19 20:19:43.836: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2760FB28, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:19:43.836: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Sent: PRACK sip:+18662966457@4.55.23.33:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK799C19D1 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Date: Fri, 19 Feb 2016 20:19:34 GMT Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 103 PRACK RAck: 22423 102 INVITE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Allow-Events: telephone-event Proxy-Authorization: Digest username="17866462052",realm="bumblebee.vtnoc.net",uri="sip:+18662966457@4.55.23.33:5060",response="a64cb0c01ee0b2356de4f2cb186dbbda",nonce="56c778f400003ade2d1a1a773ec81adab2a27b7968305c47",cnonce="EE93A286",qop=auth,algorithm=md5,nc=00000002 Max-Forwards: 70 Content-Length: 0
Feb 19 20:19:43.836: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2760FB28 Feb 19 20:19:45.879: //28231/EB59E1D3B413/SIP/Info/verbose/32768/ccsip_indicate_rt_packet_stats: Processing stats for callid=28231, proc_id=9 Feb 19 20:19:47.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2760FB28 with refCount = 1 Feb 19 20:19:47.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x245391FC with refCount = 1 Feb 19 20:19:47.826: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [66.147.235.3]:5060, local_address:[12.1.2.3] Feb 19 20:19:47.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2760FB28 Feb 19 20:19:47.826: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Feb 19 20:19:47.826: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2498648C Feb 19 20:19:47.826: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connid=4, transport=UDP Feb 19 20:19:47.826: //-1/xxxxxxxxxxxx/SIP/Info/info/4608/sipHolderGetConnInstance: Return existing connection for port 5060 connId 4 Feb 19 20:19:47.826: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_get_method_from_request: Unable to extract request line from message Feb 19 20:19:47.826: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog Feb 19 20:19:47.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x245391FC) counter, current msg->refCount = 2 Feb 19 20:19:47.826: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 12.1.2.3:5060;rport=62497;received=12.1.2.3;branch=z9hG4bK798DDA8 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:+18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 102 INVITE Record-Route: <sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Record-Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136> Contact: <sip:+18662966457@4.55.23.33:5060> Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE Require: 100rel RSeq: 22423 Content-Length: 231 Content-Disposition: session; handling=required Content-Type: application/sdp v=0 o=Sonus_UAC 16186 28782 IN IP4 4.55.23.33 s=SIP Media Capabilities c=IN IP4 4.55.23.6 t=0 0 m=audio 19896 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=maxptime:20
Feb 19 20:19:47.826: //28231/EB59E1D3B413/SIP/Info/verbose/1024/sipSPICheckResponseExt: Got new RR header Feb 19 20:19:47.826: //28231/EB59E1D3B413/SIP/Info/notify/1024/HandleSIP1xxSessionProgress: Dropping 183 - Duplicate or Unexpected Feb 19 20:19:47.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x245391FC) counter, current msg->refCount = 1 Feb 19 20:19:47.826: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x245391FC Feb 19 20:19:47.838: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x245391FC with refCount = 1 Feb 19 20:19:47.838: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/sipSPIAddRouteHeaders: status = TRUE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Feb 19 20:19:47.838: //28231/EB59E1D3B413/SIP/Info/info/4096/sipSPISendPrack: Associated container=0x2F937C68 to Prack Feb 19 20:19:47.838: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:19:47.838: //28231/EB59E1D3B413/SIP/Transport/sipSPISendPrack: Sending PRACK to the transport layer Feb 19 20:19:47.838: //28231/EB59E1D3B413/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:19:47.838: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: msg=0x245391FC, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x0 Feb 19 20:19:47.838: //28231/EB59E1D3B413/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:47.838: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:19:47.838: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:19:47.838: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x2B6BA190 is already on connection=0x24D9EACC context_list Feb 19 20:19:47.838: //28231/EB59E1D3B413/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x245391FC Feb 19 20:19:47.838: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x245391FC, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:19:47.838: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Sent: PRACK sip:+18662966457@4.55.23.33:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK799C19D1 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Date: Fri, 19 Feb 2016 20:19:34 GMT Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 103 PRACK RAck: 22423 102 INVITE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Allow-Events: telephone-event Proxy-Authorization: Digest username="17866462052",realm="bumblebee.vtnoc.net",uri="sip:+18662966457@4.55.23.33:5060",response="a64cb0c01ee0b2356de4f2cb186dbbda",nonce="56c778f400003ade2d1a1a773ec81adab2a27b7968305c47",cnonce="EE93A286",qop=auth,algorithm=md5,nc=00000002 Max-Forwards: 70 Content-Length: 0
Feb 19 20:19:47.838: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x245391FC Feb 19 20:19:51.839: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x245391FC with refCount = 1 Feb 19 20:19:51.839: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/sipSPIAddRouteHeaders: status = TRUE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Feb 19 20:19:51.839: //28231/EB59E1D3B413/SIP/Info/info/4096/sipSPISendPrack: Associated container=0x2F937C68 to Prack Feb 19 20:19:51.839: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:19:51.839: //28231/EB59E1D3B413/SIP/Transport/sipSPISendPrack: Sending PRACK to the transport layer Feb 19 20:19:51.839: //28231/EB59E1D3B413/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:19:51.839: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: msg=0x245391FC, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x0 Feb 19 20:19:51.839: //28231/EB59E1D3B413/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:51.839: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:19:51.839: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:19:51.839: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x2B6BA190 is already on connection=0x24D9EACC context_list Feb 19 20:19:51.839: //28231/EB59E1D3B413/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x245391FC Feb 19 20:19:51.839: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x245391FC, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:19:51.839: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Sent: PRACK sip:+18662966457@4.55.23.33:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK799C19D1 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Date: Fri, 19 Feb 2016 20:19:34 GMT Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 103 PRACK RAck: 22423 102 INVITE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Allow-Events: telephone-event Proxy-Authorization: Digest username="17866462052",realm="bumblebee.vtnoc.net",uri="sip:+18662966457@4.55.23.33:5060",response="a64cb0c01ee0b2356de4f2cb186dbbda",nonce="56c778f400003ade2d1a1a773ec81adab2a27b7968305c47",cnonce="EE93A286",qop=auth,algorithm=md5,nc=00000002 Max-Forwards: 70 Content-Length: 0
Feb 19 20:19:51.839: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x245391FC Feb 19 20:19:52.083: //28231/EB59E1D3B413/SIP/Info/verbose/32768/ccsip_indicate_rt_packet_stats: Processing stats for callid=28231, proc_id=9 Feb 19 20:19:55.616: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x245391FC with refCount = 1 Feb 19 20:19:55.616: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2760FB28 with refCount = 1 Feb 19 20:19:55.616: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [66.147.235.3]:5060, local_address:[12.1.2.3] Feb 19 20:19:55.616: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x245391FC Feb 19 20:19:55.616: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Feb 19 20:19:55.616: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2498648C Feb 19 20:19:55.616: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connid=4, transport=UDP Feb 19 20:19:55.616: //-1/xxxxxxxxxxxx/SIP/Info/info/4608/sipHolderGetConnInstance: Return existing connection for port 5060 connId 4 Feb 19 20:19:55.616: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_get_method_from_request: Unable to extract request line from message Feb 19 20:19:55.616: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog Feb 19 20:19:55.616: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x2760FB28) counter, current msg->refCount = 2 Feb 19 20:19:55.616: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 12.1.2.3:5060;rport=62497;received=12.1.2.3;branch=z9hG4bK798DDA8 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:+18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 102 INVITE Record-Route: <sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Record-Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136> Contact: <sip:+18662966457@4.55.23.33:5060> Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE Require: 100rel RSeq: 22423 Content-Length: 231 Content-Disposition: session; handling=required Content-Type: application/sdp v=0 o=Sonus_UAC 16186 28782 IN IP4 4.55.23.33 s=SIP Media Capabilities c=IN IP4 4.55.23.6 t=0 0 m=audio 19896 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=maxptime:20
Feb 19 20:19:55.616: //28231/EB59E1D3B413/SIP/Info/verbose/1024/sipSPICheckResponseExt: Got new RR header Feb 19 20:19:55.616: //28231/EB59E1D3B413/SIP/Info/notify/1024/HandleSIP1xxSessionProgress: Dropping 183 - Duplicate or Unexpected Feb 19 20:19:55.616: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x2760FB28) counter, current msg->refCount = 1 Feb 19 20:19:55.616: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2760FB28 Feb 19 20:19:55.840: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2760FB28 with refCount = 1 Feb 19 20:19:55.840: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/sipSPIAddRouteHeaders: status = TRUE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Feb 19 20:19:55.840: //28231/EB59E1D3B413/SIP/Info/info/4096/sipSPISendPrack: Associated container=0x2F937C68 to Prack Feb 19 20:19:55.840: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:19:55.840: //28231/EB59E1D3B413/SIP/Transport/sipSPISendPrack: Sending PRACK to the transport layer Feb 19 20:19:55.840: //28231/EB59E1D3B413/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:19:55.840: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: msg=0x2760FB28, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x0 Feb 19 20:19:55.840: //28231/EB59E1D3B413/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:55.840: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:19:55.840: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:19:55.840: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x2B6BA190 is already on connection=0x24D9EACC context_list Feb 19 20:19:55.840: //28231/EB59E1D3B413/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2760FB28 Feb 19 20:19:55.840: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2760FB28, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:19:55.840: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Sent: PRACK sip:+18662966457@4.55.23.33:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK799C19D1 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Date: Fri, 19 Feb 2016 20:19:34 GMT Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 103 PRACK RAck: 22423 102 INVITE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Allow-Events: telephone-event Proxy-Authorization: Digest username="17866462052",realm="bumblebee.vtnoc.net",uri="sip:+18662966457@4.55.23.33:5060",response="a64cb0c01ee0b2356de4f2cb186dbbda",nonce="56c778f400003ade2d1a1a773ec81adab2a27b7968305c47",cnonce="EE93A286",qop=auth,algorithm=md5,nc=00000002 Max-Forwards: 70 Content-Length: 0
Feb 19 20:19:55.840: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2760FB28 Feb 19 20:19:57.835: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/sipSPIGetRejectedRequestSyslog: Syslog Timer re-started for silent discard Feb 19 20:19:57.997: //28231/EB59E1D3B413/SIP/Info/verbose/32768/ccsip_indicate_rt_packet_stats: Processing stats for callid=28231, proc_id=9 Feb 19 20:19:59.841: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2760FB28 with refCount = 1 Feb 19 20:19:59.841: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/sipSPIAddRouteHeaders: status = TRUE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Feb 19 20:19:59.841: //28231/EB59E1D3B413/SIP/Info/info/4096/sipSPISendPrack: Associated container=0x2F937C68 to Prack Feb 19 20:19:59.841: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:19:59.841: //28231/EB59E1D3B413/SIP/Transport/sipSPISendPrack: Sending PRACK to the transport layer Feb 19 20:19:59.841: //28231/EB59E1D3B413/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:19:59.841: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: msg=0x2760FB28, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x0 Feb 19 20:19:59.841: //28231/EB59E1D3B413/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:19:59.841: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:19:59.841: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:19:59.841: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x2B6BA190 is already on connection=0x24D9EACC context_list Feb 19 20:19:59.841: //28231/EB59E1D3B413/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2760FB28 Feb 19 20:19:59.841: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2760FB28, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:19:59.841: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Sent: PRACK sip:+18662966457@4.55.23.33:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK799C19D1 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Date: Fri, 19 Feb 2016 20:19:34 GMT Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 103 PRACK RAck: 22423 102 INVITE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Allow-Events: telephone-event Proxy-Authorization: Digest username="17866462052",realm="bumblebee.vtnoc.net",uri="sip:+18662966457@4.55.23.33:5060",response="a64cb0c01ee0b2356de4f2cb186dbbda",nonce="56c778f400003ade2d1a1a773ec81adab2a27b7968305c47",cnonce="EE93A286",qop=auth,algorithm=md5,nc=00000002 Max-Forwards: 70 Content-Length: 0
Feb 19 20:19:59.841: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2760FB28 Feb 19 20:20:03.843: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2760FB28 with refCount = 1 Feb 19 20:20:03.843: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/sipSPIAddRouteHeaders: status = TRUE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Feb 19 20:20:03.843: //28231/EB59E1D3B413/SIP/Info/info/4096/sipSPISendPrack: Associated container=0x2F937C68 to Prack Feb 19 20:20:03.843: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:20:03.843: //28231/EB59E1D3B413/SIP/Transport/sipSPISendPrack: Sending PRACK to the transport layer Feb 19 20:20:03.843: //28231/EB59E1D3B413/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:20:03.843: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: msg=0x2760FB28, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x0 Feb 19 20:20:03.843: //28231/EB59E1D3B413/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:20:03.843: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:20:03.843: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:20:03.843: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x2B6BA190 is already on connection=0x24D9EACC context_list Feb 19 20:20:03.843: //28231/EB59E1D3B413/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2760FB28 Feb 19 20:20:03.843: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2760FB28, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:20:03.843: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Sent: PRACK sip:+18662966457@4.55.23.33:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK799C19D1 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Date: Fri, 19 Feb 2016 20:19:34 GMT Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 103 PRACK RAck: 22423 102 INVITE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Allow-Events: telephone-event Proxy-Authorization: Digest username="17866462052",realm="bumblebee.vtnoc.net",uri="sip:+18662966457@4.55.23.33:5060",response="a64cb0c01ee0b2356de4f2cb186dbbda",nonce="56c778f400003ade2d1a1a773ec81adab2a27b7968305c47",cnonce="EE93A286",qop=auth,algorithm=md5,nc=00000002 Max-Forwards: 70 Content-Length: 0
Feb 19 20:20:03.843: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2760FB28 Feb 19 20:20:04.295: //28231/EB59E1D3B413/SIP/Info/verbose/32768/ccsip_indicate_rt_packet_stats: Processing stats for callid=28231, proc_id=9 Feb 19 20:20:07.844: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x2760FB28 with refCount = 1 Feb 19 20:20:07.844: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/sipSPIAddRouteHeaders: status = TRUE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Feb 19 20:20:07.844: //28231/EB59E1D3B413/SIP/Info/info/4096/sipSPISendPrack: Associated container=0x2F937C68 to Prack Feb 19 20:20:07.844: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:20:07.844: //28231/EB59E1D3B413/SIP/Transport/sipSPISendPrack: Sending PRACK to the transport layer Feb 19 20:20:07.844: //28231/EB59E1D3B413/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:20:07.844: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: msg=0x2760FB28, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x0 Feb 19 20:20:07.844: //28231/EB59E1D3B413/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:20:07.844: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:20:07.844: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:20:07.844: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x2B6BA190 is already on connection=0x24D9EACC context_list Feb 19 20:20:07.844: //28231/EB59E1D3B413/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2760FB28 Feb 19 20:20:07.844: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2760FB28, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:20:07.844: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Sent: PRACK sip:+18662966457@4.55.23.33:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK799C19D1 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Date: Fri, 19 Feb 2016 20:19:34 GMT Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 103 PRACK RAck: 22423 102 INVITE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Allow-Events: telephone-event Proxy-Authorization: Digest username="17866462052",realm="bumblebee.vtnoc.net",uri="sip:+18662966457@4.55.23.33:5060",response="a64cb0c01ee0b2356de4f2cb186dbbda",nonce="56c778f400003ade2d1a1a773ec81adab2a27b7968305c47",cnonce="EE93A286",qop=auth,algorithm=md5,nc=00000002 Max-Forwards: 70 Content-Length: 0
Feb 19 20:20:07.844: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2760FB28 Feb 19 20:20:11.231: //28231/EB59E1D3B413/SIP/Info/verbose/32768/ccsip_indicate_rt_packet_stats: Processing stats for callid=28231, proc_id=9 Feb 19 20:20:11.615: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x245391FC with refCount = 1 Feb 19 20:20:11.615: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x27321740 with refCount = 1 Feb 19 20:20:11.615: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [66.147.235.3]:5060, local_address:[12.1.2.3] Feb 19 20:20:11.615: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x245391FC Feb 19 20:20:11.615: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Feb 19 20:20:11.615: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2498648C Feb 19 20:20:11.615: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connid=4, transport=UDP Feb 19 20:20:11.615: //-1/xxxxxxxxxxxx/SIP/Info/info/4608/sipHolderGetConnInstance: Return existing connection for port 5060 connId 4 Feb 19 20:20:11.615: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_get_method_from_request: Unable to extract request line from message Feb 19 20:20:11.615: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog Feb 19 20:20:11.615: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x27321740) counter, current msg->refCount = 2 Feb 19 20:20:11.615: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 12.1.2.3:5060;rport=62497;received=12.1.2.3;branch=z9hG4bK798DDA8 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:+18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 102 INVITE Record-Route: <sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Record-Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136> Contact: <sip:+18662966457@4.55.23.33:5060> Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE Require: 100rel RSeq: 22423 Content-Length: 231 Content-Disposition: session; handling=required Content-Type: application/sdp v=0 o=Sonus_UAC 16186 28782 IN IP4 4.55.23.33 s=SIP Media Capabilities c=IN IP4 4.55.23.6 t=0 0 m=audio 19896 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=maxptime:20
Feb 19 20:20:11.615: //28231/EB59E1D3B413/SIP/Info/verbose/1024/sipSPICheckResponseExt: Got new RR header Feb 19 20:20:11.615: //28231/EB59E1D3B413/SIP/Info/notify/1024/HandleSIP1xxSessionProgress: Dropping 183 - Duplicate or Unexpected Feb 19 20:20:11.615: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x27321740) counter, current msg->refCount = 1 Feb 19 20:20:11.615: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x27321740 Feb 19 20:20:11.845: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x27321740 with refCount = 1 Feb 19 20:20:11.845: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/sipSPIAddRouteHeaders: status = TRUE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Feb 19 20:20:11.845: //28231/EB59E1D3B413/SIP/Info/info/4096/sipSPISendPrack: Associated container=0x2F937C68 to Prack Feb 19 20:20:11.845: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:20:11.845: //28231/EB59E1D3B413/SIP/Transport/sipSPISendPrack: Sending PRACK to the transport layer Feb 19 20:20:11.845: //28231/EB59E1D3B413/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:20:11.845: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: msg=0x27321740, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x0 Feb 19 20:20:11.845: //28231/EB59E1D3B413/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:20:11.845: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:20:11.845: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:20:11.845: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x2B6BA190 is already on connection=0x24D9EACC context_list Feb 19 20:20:11.845: //28231/EB59E1D3B413/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x27321740 Feb 19 20:20:11.845: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x27321740, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:20:11.845: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Sent: PRACK sip:+18662966457@4.55.23.33:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK799C19D1 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:18662966457@bumblebee.vtnoc.net>;tag=gK04fa5845 Date: Fri, 19 Feb 2016 20:19:34 GMT Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 103 PRACK RAck: 22423 102 INVITE Route: <sip:66.147.235.3:5060;lr;ftag=B8F1A5F4-1DF9;did=12.14cf1136>,<sip:198.8.62.14:5060;lr;ftag=B8F1A5F4-1DF9> Allow-Events: telephone-event Proxy-Authorization: Digest username="17866462052",realm="bumblebee.vtnoc.net",uri="sip:+18662966457@4.55.23.33:5060",response="a64cb0c01ee0b2356de4f2cb186dbbda",nonce="56c778f400003ade2d1a1a773ec81adab2a27b7968305c47",cnonce="EE93A286",qop=auth,algorithm=md5,nc=00000002 Max-Forwards: 70 Content-Length: 0
Feb 19 20:20:11.845: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x27321740 Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x27321740 with refCount = 1 Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x276089E0 with refCount = 1 Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [66.147.235.3]:5060, local_address:[12.1.2.3] Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x27321740 Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2498648C Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2498648C, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connid=4, transport=UDP Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/info/4608/sipHolderGetConnInstance: Return existing connection for port 5060 connId 4 Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_get_method_from_request: Unable to extract request line from message Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x276089E0) counter, current msg->refCount = 2 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 482 Loop Detected Via: SIP/2.0/UDP 12.1.2.3:5060;rport=62497;received=12.1.2.3;branch=z9hG4bK798DDA8 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:+18662966457@bumblebee.vtnoc.net>;tag=gK048030a2 Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 CSeq: 102 INVITE Content-Length: 0
Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/verbose/1024/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentGTD: No GTD found in inbound container Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x27321740 with refCount = 1 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 1 event Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/notify/4096/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/notify/4096/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_offer_ans_handle_call_active: Feb 19 20:20:12.133: //28231/EB59E1D3B413/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 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_offer_ans_dialog_established_hdlr: Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_iwf_handle_generic_event: Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sccp_early_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_CALL_ACTIVE Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/4096/is_mode_sip_sip: Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/4096/is_mode_sip_h323: Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/4096/is_mode_sip_h32x: Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/is_mode_sip_sccp: Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/4096/ccsip_iwf_set_tdm_ip_call_active: Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_sccp_mid_dialog_container Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_MID_DIALOG_IDLE Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/4096/sipSPISendAck: Associated container=0x2F939630 to Ack Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Transport/sipSPISendAck: Sending ACK to the transport layer Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: msg=0x27321740, addr=66.147.235.3, port=5060, sentBy_port=0, local_addr=12.1.2.3, is_req=1, transport=1, switch=0, callBack=0x0 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:66.147.235.3, rport:5060 with laddr:12.1.2.3
Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x2B6BA190 is already on connection=0x24D9EACC context_list Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x27321740 Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x27321740, addr=66.147.235.3, port=5060, local_addr=12.1.2.3, connId=4 for UDP Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/critical/1024/act_recdproc_new_message_response: Received a 4/5/6xx message with StatusCode: 482 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_set_release_source_for_peer: ownCallId[28231], src[4] Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/critical/4096/sipSPIInitiateDisconnect: Initiate call disconnect(127) for outgoing call Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x2118DDB0 Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentQSIG: No QSIG Body found in inbound container Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentQ931: No RawMsg Body found in inbound container Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_ipip_media_service_get_event_data: Event id = 29 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/critical/32768/ccsip_ipip_media_forking_post_event: MF: Not a Anchor SIP leg.. Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/State/sipSPIChangeState: 0x2B6BA190 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE) Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x276089E0) counter, current msg->refCount = 1 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_ipip_media_service_get_event_data: Event id = 18 Feb 19 20:20:12.133: //28231/EB59E1D3B413/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_XCODER_RESET_STREAM Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/verbose/256/sipSPIResetXcoder: *****CLEANING UP XCODER RESOURCES***** Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/verbose/256/sipSPIResetXcoder: *****CLEANING UP XCODER RESOURCES***** Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/verbose/256/sipSPIResetXcoder: Xcoder resource already cleaned up Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/State/ccsip_cnfsm_debugs: IPIPMS:next_state:S_IPIP_MEDIA_SERV_STATE_IDLE Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:2FA7142C Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Msg/ccsipDisplayMsg: Sent: ACK sip:18662966457@bumblebee.vtnoc.net:5060 SIP/2.0 Via: SIP/2.0/UDP 12.1.2.3:5060;branch=z9hG4bK798DDA8 From: "DJ's Test phone" <sip:200@bumblebee.vtnoc.net>;tag=B8F1A5F4-1DF9 To: <sip:+18662966457@bumblebee.vtnoc.net>;tag=gK048030a2 Date: Fri, 19 Feb 2016 20:19:34 GMT Call-ID: ECC8824B-D67C11E5-B418DD4E-41EF9C4A@12.1.2.3 Max-Forwards: 70 CSeq: 102 ACK Allow-Events: telephone-event Content-Length: 0
Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x27321740 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/verbose/8192/ccsip_call_statistics: Requesting stats for callid=28231 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/verbose/4096/ccsip_ipip_media_service_get_event_data: Event id = 29 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/critical/32768/ccsip_ipip_media_forking_post_event: MF: Not a Anchor SIP leg.. Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/verbose/32768/ccsip_indicate_rt_packet_stats: Processing stats for callid=28231, proc_id=1 Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SPI_EVENT Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/8192/Session-Timer/sipSTSLMain: SE: 0;refresher:none peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:1800, Configured Min-SE:1800 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/133120/sipSPIBwCacReleaseDialPeerBw: bwcac dial-peer bw 80 Kbps released for tag 13 active bw 0 Kbps Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/131072/sipSPIBwCacReleaseInterfaceBw: bwcac releasing interface BVI255 bw 80 Kbps Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/131072/sipSPIBwCacReleaseAccountedBw: bwcac released accounted bw 80000 bps Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/4096/act_disconnecting_disconnect: Disconnect now.. no defer BYE.. Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/4096/sipSPISetCommonTimer: Started generic timer type 2 for 240000 millisecs Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/verbose/8192/sipSPIDeferCallClose: Not split dataplane, bail Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/verbose/8192/sipSPIWaitForStatsBforeCallClose: Not split dataplane, bail Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/verbose/4096/sipSPICallCloseAfterFinalStat: sipSPICallCloseAfterFinalStat: Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Info/info/12288/sipSPIIcpifUpdate: CallState: 3 Playout: 29560 DiscTime:310288234 ConnTime 0 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/Media/sipSPIHandleDestroyRtpSession: stream:2FA7142C Feb 19 20:20:12.133: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x276089E0 Feb 19 20:20:12.133: //28231/EB59E1D3B413/SIP/State/sipSPIChangeState: 0x2B6BA190 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE) Feb 19 20:20:12.135: //28231/EB59E1D3B413/SIP/Call/sipSPICallInfo: The Call Setup Information is: Call Control Block (CCB) : 0x0x2B6BA190 State of The Call : STATE_DEAD TCP Sockets Used : NO Calling Number : 200 Called Number : 18662966457 Source IP Address (Sig ): 12.1.2.3 Destn SIP Req Addr:Port : 66.147.235.3:5060 Destn SIP Resp Addr:Port : 66.147.235.3:5060 Destination Name : bumblebee.vtnoc.net
Feb 19 20:20:12.135: //28231/EB59E1D3B413/SIP/Call/sipSPIMediaCallInfo: Number of Media Streams: 1 Media Stream : 1 Negotiated Codec : g711ulaw Negotiated Codec Bytes : 160 Nego. Codec payload : 0 (tx), 0 (rx) Negotiated Dtmf-relay : 6 Dtmf-relay Payload : 101 (tx), 101 (rx) Source IP Address (Media): 12.1.2.3 Source IP Port (Media): 19606 Destn IP Address (Media): 4.55.23.6 Destn IP Port (Media): 19896 Orig Destn IP Address:Port (Media): [ - ]:0
Feb 19 20:20:12.135: //28231/EB59E1D3B413/SIP/Call/sipSPICallInfo: Disconnect Cause (CC) : 127 Disconnect Cause (SIP) : 482
Feb 19 20:20:12.135: //28231/EB59E1D3B413/SIP/Info/verbose/4096/sipSPIUdeleteccCallIdFromTable: Removing call id 6E47 Feb 19 20:20:12.135: //28231/EB59E1D3B413/SIP/Info/verbose/4096/sipSPIUfreeOneCCB: Return and SIP_TIMER_REMOVE_TRANSACTION timer will free this ccb=0x2B6BA190
|