Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x3F8D988C with refCount = 1 Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x39F52954 with refCount = 1 Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.105.40.34]:5060, local_address:[10.198.10.126] Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x3F8D988C Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Transport/sipTranspPTIONS,BYE,CANCEL,REGISTER,INFO,PRACK,SUBSCRIBE,NOTIFY,UPDATE,MESSAGE,REFER Max-Forwards: 70 Supported: 100rel,timer User-Agent: Huawei SoftX3000 V300R010 Session-Expires: 300 Min-ortProcessNWNewConnMsg: context=0x0 Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Received: INVITE sip:143461321@10.198.10.126:5060;user=phone SIP/2.0 Via: SIP/2.0/UDP 10.105.40.34:5060;branch=z9hG4bKbc8bjcec8ihi7lljxcbjlxijc Call-ID: SBCm5whtnqntmxxcvjquvncct5qhwmwggt3@SoftX3000 From: ;tag=hsmvs3jn-CC-34 To: CSeq: 1 INVITE Allow: INVITE,ACK,OSE: 90 Contact: Content-Length: 310 Content-Type: application/sdp v=0 o=HuaweiSoftX3000 21176945 21176945 IN IP4 10.105.40.34 s=Sip Call c=IN IP4 10.105.40.34 t=0 0 m=audio 36738 RTP/AVP 8 0 18 3 97 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmcsip_new_msg_preprocessor: Checking Invite Dialog Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToTable: Added context(0x3EF78700) with key=[7] to tableap:18 G729/8000 a=rtpmap:3 GSM/8000 a=rtpmap:97 telephone-event/8000 a=ptime:20 a=fmtp:97 0-15 a=fmtp:18 annexb=no Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/c Sep 8 10:21:19.598: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_service_init: Sep 8 10:21:19.598: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_service_init: Sep 8 10:21:19.598: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_forking_init: MF: Queue is initialised.. Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.105.40.34,Port 5060, Transport 1, SentBy Port 5060vrfid 0 Sep 8 10:21:19.598: //-1/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0 Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.198.10.126 for SIP Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.198.10.126 for SIP Sep 8 10:21:19.598: //-1/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 10.198.10.126 Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 10.198.10.126 Sep 8 10:21:19.598: //-1/D167D7898023/SIP/State/sipSPIChangeState: 0x3EF78700 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.105.40.34,Port 5060, Transport 1, SentBy Port 5060vrfid 0 Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone UTC to SIP default timezone = GMT Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.105.40.34,Port 5060, Transport 1, SentBy Port 5060vrfid 0 Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x39F52954) counter, current msg->refCount = 2 Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Error/httpish_msg_free: Freeing NULL pointer! Sep 8 10:21:19.598: //-1/D167D7898023/SIP/Info/verbose/4096/sipSPIAssignCcbLastRequest: Current ccb(0x3EF78700)->last_request = 0x39F52954, refCount = 2 Sep 8 10:21:19.598: //-1/xxxxxxxxxxxx/SIP/Info/info/2048/sipSPICheckIpip: VOIP dialpeer (peer=0x3CD5B29C) found for sip_user: 143461321 Sep 8 10:21:19.598: //-1/D167D7898023/SIP/Info/info/2048/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done Sep 8 10:21:19.598: //-1/D167D7898023/SIP/Info/info/4096/sipSPISetCallingInfo: calling host comes from From: 10.105.40.34 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/verbose/4096/sipSPIUpdateCallingInfoUsingRpidOrFrom: Updating Calling Info with FROM header data Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/2048/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done Sep 8 10:21:19.602: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentGTD: No GTD found in inbound container Sep 8 10:21:19.602: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentCSTA: No CSTA found in inbound container Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to table. ccb=0x3EF78700 key=SBCm5whtnqntmxxcvjquvncct5qhwmwggt3@SoftX3000143461321 balance 1 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/8192/sipSPIMatchSrcIpGroup: Match not found on carrier id Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/critical/8192/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 143461321 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/critical/8192/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 188207994 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/12288/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name , number 188207994, Calling oct3 0x00, oct_3a 0x80, Called number 143461321 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/verbose/1024/sipSPIGetViaHostInURLFormat: VIA URL:sip:10.105.40.34:5060, Host:10.105.40.34 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/verbose/67584/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 188207994 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/critical/1024/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/critical/1024/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/critical/10240/sipSPIGetCallConfig: No match found for P-Called-Party-ID Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/2048/sipSPIGetCallConfig: Peer tag 200 matched for incoming call Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/verbose/1024/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0 Sep 8 10:21:19.602: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.198.10.126 for SIP Sep 8 10:21:19.602: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.198.10.126 for SIP Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 10.198.10.126 Sep 8 10:21:19.602: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 10.198.10.126 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/verbose/1024/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/verbose/2048/sipSPIGetCallConfig: Media Antitrombone disabled Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/8192/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/2304/sipSPISetMediaFlowMode: xcoder high-density disabled Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/8192/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/verbose/4/update_video_params_from_config: Checking Video Type Rate=-1 video_codec_allowed=1F Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/verbose/12288/sipSPIGetModemInfoPerCall: peer_callID=0 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/critical/32768/ccsip_ipip_media_forking_update_preferred_codec: MF: Not a Forked SIP leg.. Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/8704/sipSPIGetCallConfig: Incoming: No defer BYE for last call stats Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/verbose/1/ccsip_set_srtp_config: No Srtp configure for this leg. Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/8192/sipSPIGetCallConfig: Media forking disabled Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/34816/ccsip_ipip_media_forking_anchor_leg_config: MF: en_p->encap_s.voIP.voipPeerCfgMediaClass = 0 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/34816/ccsip_ipip_media_forking_anchor_leg_config: MF: Dial-peer has no media class recorder. Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/36864/sipSPIMFChangeState: MF: Prev state = 0 & New state = -1 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/32768/ccsip_ipip_media_forking_anchor_leg_reset: MF: Anchor leg config reset done... Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/32768/ccsip_ipip_media_forking_intra_frame_request_config: MF: FIR en_p->encap_s.voIP.voipPeerCfgMediaClass = 0 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/32768/ccsip_ipip_media_forking_get_forked_leg_config: MF: This leg is not forked call leg. Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/critical/11264/ccsipInitDSCPPolicyInfo: No DSCP Profile configured, No RPH 2 DSCP Mapping and DSCP policing Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/verbose/8192/sipSPIGetCallConfig: Initilise the DSCP policy Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/verbose/8192/sipSPICheckFAAnatAssymetricOrDO2EO: Not a SIP-SIP call or not in FA mode Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/notify/8192/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/verbose/10240/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/verbose/2048/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/notify/10240/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/4096/sipSPIContinueNewMsgInvite: Calling name , number 188207994, Calling oct3 0x00, oct_3a 0x80, ext_priv 0x00, Called number 143461321, oct3 0x00 Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/4096/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/4096/sipSPIContinueNewMsgInvite: Requires reliable-provisional support Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/critical/10240/sipSPIValidateRequestUri: Not Enabled Sep 8 10:21:19.602: //-1/D167D7898023/SIP/Info/info/131072/sipSPIRscmsmAvail: Value returned by check is = 0 Sep 8 10:21:19.602: //13/D167D7898023/SIP/Info/critical/4096/sipSPICheckOutBoundDpProvisioning: Cannot obtain the the header bitmap Sep 8 10:21:19.602: //13/D167D7898023/SIP/Info/critical/8192/sipSPI_ipip_IsSDPPassthruEnabled: - 0 Sep 8 10:21:19.602: //13/D167D7898023/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ Sep 8 10:21:19.602: //13/D167D7898023/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:0, container:23F2D1BC Sep 8 10:21:19.602: //13/D167D7898023/SIP/Info/info/8192/Session-Timer/sipSTSLExtractSessionExpiresHdr: Session-Expires value: 300 refresher: none Sep 8 10:21:19.602: //13/D167D7898023/SIP/Info/info/8192/Session-Timer/sipSTSLExtractMinSEHdr: Min-SE Duration: 90 Sep 8 10:21:19.602: //13/D167D7898023/SIP/Info/info/8192/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ Sep 8 10:21:19.602: //13/D167D7898023/SIP/Info/verbose/8192/Session-Timer/sipSTSLInitialSRReqPeerEventGen: sending received session expires to the peer leg Sep 8 10:21:19.602: //13/D167D7898023/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_PASS_ST_PARAMS, SE Value:300, SE Refresher:none, Min-SE Value:300, flags:2001 Sep 8 10:21:19.602: //13/D167D7898023/SIP/Info/info/8192/Session-Timer/sipSTSLMain: SE: 300;refresher:none peer refresher:none, flags:2001, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:300, Configured Min-SE:300 Sep 8 10:21:19.602: //13/D167D7898023/SIP/Info/critical/1024/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container Sep 8 10:21:19.602: //13/D167D7898023/SIP/Info/critical/1024/sipSPIProcessDiversionHeader: No diversion headers recvd from app container Sep 8 10:21:19.602: //13/D167D7898023/SIP/Info/critical/16384/sipSPIProcessReplacesHeader: No replaces hdr found Sep 8 10:21:19.602: //-1/xxxxxxxxxxxx/SIP/Info/verbose/1024/sipSPIGetContentCPA: No CPA found in inbound container Sep 8 10:21:19.602: //13/D167D7898023/SIP/Info/verbose/1024/sipSPIProcessCPA: No x-cisco-cpa content found Sep 8 10:21:19.602: //13/D167D7898023/SIP/Info/verbose/1/sipSPIDoMediaNegotiation: Number of m-lines = 1 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/1/sipSPIValidateConnectionAddress: Dest port = 36738 SIP: (13) Attribute mid, level 1 instance 1 not found. Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: peer_tag=200 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_media_ip_address_to_bind: VRF id = 0 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.198.10.126 for SIP Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.198.10.126 for SIP Sep 8 10:21:19.606: //13/D167D7898023/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.198.10.126 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/sipSPICheckDynPayloadUse: Dynamic payload(97) reserved for codec No Codec Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/critical/1/sipSPICheckDynPayloadUse: Dynamic payload(97) could not be reserved as its in use by other codec Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/critical/1/sipSPIUpdateDynamicPT: Requested payload-Type (97) is reserved by another application Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 97 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 97 for Codec: Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/1/sipSPIDoAudioNegotiation: Codec (g711ulaw) Negotiation Successful on Static Payload for m-line 1 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/1/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_ptime_to_codec_bytes: Values :Codec: g711ulaw ptime :20, codecbytes: 160 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711ulaw Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/8/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/1/sipSPIDoDTMFRelayNegotiation: m-line index 1 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/sipSPICheckDynPayloadUse: Dynamic payload(97) reserved for codec Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/critical/1/sipSPICheckDynPayloadUse: Dynamic payload(97) could not be reserved as its in use by other codec Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/critical/1/sipSPIUpdateDynamicPT: Requested payload-Type (97) is reserved by another application Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 97 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec: Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/1/sipSPIReserveRtpNtePayload: Reserved the payload type 97 for RTP-NTE Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/32/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/1/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events. Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/info/8209/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/critical/8193/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay Sep 8 10:21:19.606: //13/D167D7898023/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 Sep 8 10:21:19.606: //13/D167D7898023/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=10.105.40.34, dest_port=36738 Sep 8 10:21:19.606: //13/D167D7898023/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING) Sep 8 10:21:19.606: //13/D167D7898023/SIP/Media/sipSPIUpdCallWithSdpInfo: Preferred Codec : g711ulaw, bytes :160 Preferred DTMF relay : sip-notify Preferred NTE payload : 97 Early Media : No Delayed Media : No Bridge Done : No New Media : No DSP DNLD Reqd : No Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Sep 8 10:21:19.606: //13/D167D7898023/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.198.10.126 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/4096/ccsip_offer_ans_handle_rcvd_sdp: Sep 8 10:21:19.606: //13/D167D7898023/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_IDLE, event:E_SIP_INVITE_SDP_RCVD Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/4096/ccsip_offer_ans_is_invite_offer_valid: TRUE Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/4096/ccsip_offer_ans_common_offer_rcvd_hdlr: Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/4096/ccsip_iwf_handle_network_event: Sep 8 10:21:19.606: //13/D167D7898023/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_RCVD_SDP Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/4096/sip_iwf_def_ed_rcvd_sdp_hdlr: Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/1/sipSPIAssignStreamCallId: Assigning streamid 13 to stream 1. Old streamid = -1 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/1/sipSPI_initialize_audio_channelInfo_from_sdp: stream_callid = 13, peer_stream_callid = -1 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/8/sipSPI_ipip_init_stream_ex_caps_params: T38 version 0 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/8/sipSPI_ipip_init_stream_ex_caps_params: CCB fax rate 2 ipip_caps rate 14400 SIP: (13) setup attribute, level 1 instance 1 not found. SIP: (13) connection attribute, level 1 instance 1 not found. SIP: (13) Attribute label, level 1 instance 1 not found. SIP: (13) a=framerate attribute, level 1 instance 1 not found. Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/1025/sipSPI_initialize_audio_channelInfo_from_sdp: Populating Address in channelInfo Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/1/sipSPI_initialize_audio_channelInfo_from_sdp: Media dest addr for stream 1='10.105.40.34', port=36738 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/1/sip_iwf_sip_copy_audio_sdp_to_local_channelInfo: Processing Media line = 1; Codec = g711alaw; PType = 8 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/1/codec_found: Codec to be matched: g711alaw(6) Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/1/codec_found: Match Not Found for g711alaw. Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/1/sip_iwf_sip_copy_audio_sdp_to_local_channelInfo: Processing Media line = 1; Codec = g711ulaw; PType = 0 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/1/codec_found: Codec to be matched: g711ulaw(5) Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/1/codec_found: Match Found at index 0. Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/1/sip_iwf_sip_copy_audio_sdp_to_local_channelInfo: Add Channel for Codec g711ulaw Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/1/sip_iwf_sip_copy_audio_sdp_to_local_channelInfo: Media negotiation done for m-line=1: negotiated_ptime=20, negotiated_codec_bytes=160 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/1/sipSPI_ipip_update_codec_params_in_stream_channelInfo: Adding negotiated codec g711ulaw ptype 0 time 20, bytes 160 as channel 0 mline 1 ss 1 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/131073/sipSPIBwCacCalcAudioBandwidth: calculated audio bandwidth : codec g711ulaw bw 64000 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Media/sipSPISelectCodecVersion: Codec (g729r8) is not in preferred list Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/1/sipSPI_ipip_update_static_codec_params: An exact codec match not configured, using interoperable codec g729r8 pre-ietf Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/1/sip_iwf_sip_copy_audio_sdp_to_local_channelInfo: Processing Media line = 1; Codec = g729r8 pre-ietf; PType = 18 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/1/codec_found: Codec to be matched: g729r8 pre-ietf(0) Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/1/codec_found: Match Not Found for g729r8 pre-ietf. Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/1/sip_iwf_sip_copy_audio_sdp_to_local_channelInfo: Processing Media line = 1; Codec = gsmfr; PType = 3 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/1/codec_found: Codec to be matched: gsmfr(10) Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/1/codec_found: Match Not Found for gsmfr. Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/32/sipSPI_ipip_upd_2833_dtmf_params: setting ipip_caps DTMF to RFC2833: callid = 13, dtmf = 6 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/1/sip_iwf_sip_copy_audio_sdp_to_local_channelInfo: Processing Media line = 1; Codec = No Codec ; PType = 97 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/16/sipSPIGetPreferredSrtpSuiteForBw: Return : 0 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/verbose/16/sipSPIBwCacGetSrtpOverhead: Return: 0 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Media/sipSPIDisplayStreamInfo: Stream type : voice+dtmf Media line : 1 State : STREAM_ADDING (2) Stream address type : 1 Callid : 13 Peer Callid : -1 RTP/SRTP Negotiated : 8 Negotiated Codec : g711ulaw, bytes :160 Nego. Codec payload : 0 (tx), 0 (rx) Negotiated DTMF relay : rtp-nte Negotiated NTE payload : 97 (tx), 97 (rx) Negotiated CN payload : 0 Media Srce Addr/Port : [10.198.10.126]:0 Media Dest Addr/Port : [10.105.40.34]:36738 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/4097/sipSPI_ipip_calculate_channel_count: Number of streams to report = 1 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/critical/1/sip_iwf_sip_copy_sdp_to_stream_channelInfo: Not updating call entry. Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/1/sip_iwf_def_ed_rcvd_sdp_hdlr: Setting media_direction to 0 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/131072/sipSPIBwCacUpdateAccountedBw: bwcac update accounted BW Option 0 flow mode flow-through audio bw 80000 bps video bw 0 bps fax bw 0 bps total bw 80000 bps accounted bw 0 bps Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/131072/sipSPIBwCacUpdateInterfaceBw: bwcac acquiring interface GigabitEthernet0/1 bw 80 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/131072/sipSPIBwCacUpdateAccountedBw: bwcac update accounted bw (initial offer) accounted bw set to 80000 Sep 8 10:21:19.606: //13/D167D7898023/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:S_SIP_IWF_SDP_RCVD_AWAIT_PEER_EVENT Sep 8 10:21:19.606: //13/D167D7898023/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_EARLY_DIALOG_OFFER_RCVD Sep 8 10:21:19.606: //13/D167D7898023/SIP/Media/sipSPIUpdCallWithSdpInfo: Stream type : voice+dtmf Media line : 1 State : STREAM_ADDING (2) Stream address type : 1 Callid : 13 Negotiated Codec : g711ulaw, bytes :160 Nego. Codec payload : 0 (tx), 0 (rx) Negotiated DTMF relay : rtp-nte Negotiated NTE payload : 97 (tx), 97 (rx) Negotiated CN payload : 0 Media Srce Addr/Port : [10.198.10.126]:0 Media Dest Addr/Port : [10.105.40.34]:36738 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/33/sipSPIHandleInviteMedia: Negotiated Codec : g711ulaw, bytes :160 Preferred Codec : g711ulaw, bytes :160 Preferred DTMF relay 1 : 8 Preferred DTMF relay 2 : 6 Negotiated DTMF relay : 6 Preferred and Negotiated NTE payloads: 97 97 Preferred and Negotiated NSE payloads: 100 0 Preferred and Negotiated Modem Relay: 0 0 Preferred and Negotiated V150.1 Modem Passthrough: 0 0 Preferred and Negotiated V150.1 Modem Relay: 0 0 Preferred and Negotiated Modem Relay GwXid: 1 0 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/133120/sipSPIBwCacIsDialPeerBwAvailable: bwcac NOP dial-peer bw available tag 200 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/1/sipSPIBwCacIsInterfaceBwAvailable: bwcac interface bw threshold not configured Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/131072/sipSPIBwCacVerifyBwThreshold: bwcac verify bw threshold, bw available allow call total bw 80000 bps Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/131073/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/131072/sipSPIDoStreamQoSNegotiation: Best effort Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/131072/sipSPICanSetFallbackFlag: Local Fallback is not active Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 16408 for stream 1 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/1/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=16408 Sep 8 10:21:19.606: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/info/1/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 16408 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/1/sipSPIUpdateSrcSdpVariablePart: SIP update src sdp, negoitated codec 5, payload type 0 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/notify/32/sipSPIUpdateSrcSdpVariablePart: Negotiated method of dtmf relayand pyld: 6 97 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/32/sipSPIUpdateSrcSdpVariablePart: max_event 16 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/4096/sipSPIAddBillingInfoToCcb: sipCallId for billing records = SBCm5whtnqntmxxcvjquvncct5qhwmwggt3@SoftX3000 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/16384/sipSPI_ipip_AddInvDataToTDContainer: req_uri = sip:143461321@10.198.10.126:5060;user=phone Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/16384/sipSPI_ipip_AddInvDataToTDContainer: to = Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/16384/ccsip_api_call_setup_ind: retVal = 0 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/verbose/10240/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0 Sep 8 10:21:19.606: //13/D167D7898023/SIP/Info/critical/10240/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Unsupported header passthru is not configured and no headers are present in hdr_hash_queueSIP/2.0 100 Trying Via: SIP/2.0/UDP 10.105.40.34:5060;branch=z9hG4bKbc8bjcec8ihi7lljxcbjlxijc From: ;tag=hsmvs3jn-CC-34 To: Date: Thu, 08 Sep 2016 10:21:19 GMT Call-ID: SBCm5whtnqntmxxcvjquvncct5qhwmwggt3@SoftX3000 CSeq: 1 INVITE Allow-Events: telephone-event Server: Cisco-SIPGateway/IOS-15.4.3.M4 Content-Length: 0 Sep 8 10:21:19.614: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x21A633F8 Sep 8 10:21:20.366: //13/D167D7898023/SIP/Info/info/4096/ccsip_call_alert: CCSIP_CALL_ALERT: app_diaplay_name[] app_display_num[321] Sep 8 10:21:20.366: //13/D167D7898023/SIP/Info/notify/4096/ccsip_call_alert: CCSIP_CALL_ALERT : KPML_CONFIGURED[FALSE] collect_digits[321] calledNumber[143461321] display_name[] display_num[321] Sep 8 10:21:20.366: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_ALERTING Sep 8 10:21:20.366: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_MEDIA_EVENT Sep 8 10:21:20.366: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 5 Sep 8 10:21:20.402: //13/D167D7898023/SIP/Info/info/8192/Session-Timer/sipSTSLMain: SE: 300;refresher:none peer refresher:none, flags:2001, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:300, Configured Min-SE:300 Sep 8 10:21:20.402: //13/D167D7898023/SIP/Info/verbose/4096/ccsip_buffer_media_event: Buffering event SIPSPI_EV_CC_MEDIA_EVENT - Purpose 1: FALSE Sep 8 10:21:20.686: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x21A633F8 with refCount = 1 Sep 8 10:21:20.686: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x39F52B10 with refCount = 1SIP/2.0 200 OK Via: SIP/2.0/UDP 10.105.40.34:5060;branch=z9hG4bKnexekbh8ynn8xcujxvvklhycj From: ;tag=hsmvs3jn-CC-34 To: ;tag=DF0F8-E37 Date: Thu, 08 Sep 2016 10:21:20 GMT Call-ID: SBCm5whtnqntmxxcvjquvncct5qhwmwggt3@SoftX3000 Server: Cisco-SIPGateway/IOS-15.4.3.M4 CSeq: 2 PRACK Content-Length: 0 Sep 8 10:21:20.694: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x21A633F8 Sep 8 10:21:21.970: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_MEDIA_EVENT Sep 8 10:21:32.030: //13/D167D7898023/SIP/Info/notify/1/ccsip_query_codec_info: Negotiated codec = 5 Sep 8 10:21:32.030: //13/D167D7898023/SIP/Info/verbose/8192/sipSPI_ipip_codec_byte_transrating: NOT SIP-SIP CALL. Will be addressed in future. Sep 8 10:21:32.034: //13/D167D7898023/SIP/Info/info/8192/ccsip_call_statistics: Stats are not supported for IPIP call. Sep 8 10:21:32.034: //13/D167D7898023/SIP/Info/verbose/4096/ccsip_ipip_media_service_get_event_data: Event id = 29 Sep 8 10:21:32.034: //13/D167D7898023/SIP/Info/critical/32768/ccsip_ipip_media_forking_post_event: MF: Not a Anchor SIP leg.. Sep 8 10:21:32.034: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT Sep 8 10:21:32.034: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8 Sep 8 10:21:32.034: //13/D167D7898023/SIP/Info/info/133120/sipSPIBwCacReleaseDialPeerBw: bwcac dial-peer bw 80 Kbps released for tag 200 active bw 0 Kbps Sep 8 10:21:32.034: //13/D167D7898023/SIP/Info/info/131072/sipSPIBwCacReleaseInterfaceBw: bwcac releasing interface GigabitEthernet0/1 bw 80 Kbps Sep 8 10:21:32.034: //13/D167D7898023/SIP/Info/info/131072/sipSPIBwCacReleaseAccountedBw: bwcac released accounted bw 80000 bps Sep 8 10:21:32.034: //13/D167D7898023/SIP/Error/act_sentalert_disconnect: Disconnect cause from ccapi :47 and sip_disc_cause: 503 Sep 8 10:21:32.034: //13/D167D7898023/SIP/Info/verbose/4096/sipSPISendInviteResponse: Dialog State: [1] Sep 8 10:21:32.034: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x21A633F8 with refCount = 1 Sep 8 10:21:32.034: //13/D167D7898023/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP Sep 8 10:21:32.034: //13/D167D7898023/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:503, container:23F2D9FC Sep 8 10:21:32.034: //13/D167D7898023/SIP/Info/info/8192/Session-Timer/sipSTSLMain: SE: 300;refresher:none peer refresher:none, flags:1, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:300, Configured Min-SE:300 Sep 8 10:21:32.034: //13/D167D7898023/SIP/Info/info/4096/sipSPISendInviteResponse: Associated container=0x23F2D9FC to Invite Response 503 Sep 8 10:21:32.034: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 Sep 8 10:21:32.034: //13/D167D7898023/SIP/Transport/sipSPITransportSendMessage: msg=0x21A633F8, addr=10.105.40.34, port=5060, sentBy_port=5060, local_addr=10.198.10.126, is_req=0, transport=1, switch=0, callBack=0x3598D8BC Sep 8 10:21:32.034: //13/D167D7898023/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Sep 8 10:21:32.034: //13/D167D7898023/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 Sep 8 10:21:32.034: //13/D167D7898023/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Sep 8 10:21:32.034: //13/D167D7898023/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x21A633F8 to default port=5060 Sep 8 10:21:32.034: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.105.40.34, rport:5060 with laddr:10.198.10.126 Sep 8 10:21:32.034: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x3EF78700 is already on connection=0x3E7255E0 context_list Sep 8 10:21:32.034: //13/D167D7898023/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x21A633F8 Sep 8 10:21:32.034: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x21A633F8, addr=10.105.40.34, port=5060, local_addr=10.198.10.126, connId=3 vrfid=0 for UDP Sep 8 10:21:32.034: //13/D167D7898023/SIP/Info/critical/512/sentErrResDisconnecting: Sent an 3456XX Error Response Sep 8 10:21:32.034: //13/D167D7898023/SIP/State/sipSPIChangeState: 0x3EF78700 : State change from (STATE_SENT_ALERTING, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE) Sep 8 10:21:32.034: //13/D167D7898023/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 503 Service Unavailable Via: SIP/2.0/UDP 10.105.40.34:5060;branch=z9hG4bKbc8bjcec8ihi7lljxcbjlxijc From: ;tag=hsmvs3jn-CC-34 To: ;tag=DF0F8-E37 Date: Thu, 08 Sep 2016 10:21:20 GMT Call-ID: SBCm5whtnqntmxxcvjquvncct5qhwmwggt3@SoftX3000 CSeq: 1 INVITE Allow-Events: telephone-event Server: Cisco-SIPGateway/IOS-15.4.3.M4 Reason: Q.850;cause=47 Content-Length: 0 Sep 8 10:21:32.034: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x21A633F8 Sep 8 10:21:32.046: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x21A633F8 with refCount = 1 Sep 8 10:22:31.614: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnAgeing: Holder=0x3F8D9B34 Connection=0x3E7255E0, addr=10.105.40.34, port=5060, connid=3 has been REFRESHED Sep 8 10:22:31.614: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x3F8D9B34,addr=10.105.40.34 Sep 8 10:27:31.614: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnAgeing: Connection=0x3E7255E0, addr=10.105.40.34, port=5060, connid=3 has been aged out Sep 8 10:27:31.614: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostCloseConnection: Posting UDP conn close for addr=10.105.40.34, port=5060, local_addr=10.198.10.126, connid=3 Sep 8 10:27:31.614: //-1/xxxxxxxxxxxx/SIP/Transport/sipDeleteConnInstance: Deleted conn=0x3E7255E0, connid=3, addr=10.105.40.34, port=5060, local_addr=10.198.10.126, transport=UDP Sep 8 10:27:31.614: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x3F8D9B34,addr=10.105.40.34 Sep 8 10:27:31.614: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportStopAgeingTimer: Aging timer stopped for holder=0x3F8D9B34,addr=10.105.40.34 Sep 8 10:27:31.614: //-1/xxxxxxxxxxxx/SIP/Transport/sipDeleteConnHolder: Deleted holder=0x3F8D9B34, addr=10.105.40.34, count=0 Sep 8 10:27:31.614: //-1/xxxxxxxxxxxx/SIP/Info/info/512/udpsock_close_connect: Socket fd: 0 closed for connid 3 with remote port: 5060 1