All SIP Call tracing is enabled SIP|GW|1# 000604: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.224.15] 000605: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 fo1 000606: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0 000607: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Received: INVITE sip:22490326@10.249.64.50:5060 SIP/2.0 Max-Forwards: 18 Via: SIP/2.0/UDP 10.224.150.7:5060;branch=z9hG4bKg3Zqkv7iurhqvgc7e8fbp421wn6udijgl To: "22490326 22490326" ;cscf From: ;tag=h7g4Esbg_159588558-1491835653860- Call-ID: BW1747338601004171335955028@10.224.112.10 CSeq: 741001075 INVITE Contact: Record-Route: Min-Se: 600 P-Asserted-Identity: Privacy: none Session-Expires: 1800 Content-Type: application/sdp Content-Length: 298 Allow: ACK, BYE, CANCEL, INFO, INVITE, OPTIONS, PRACK, REFER, NOTIFY, UPDATE Accept: application/media_control+xml Accept: application/sdp Accept: application/x-broadworks-call-center+xml Accept: message/cpim Accept: multipart/mixed v=0 o=BroadWorks 772714338 1 IN IP4 10.224.150.7 s=- c=IN IP4 10.224.149.68 t=0 0 m=audio 24620 RTP/AVP 18 8 100 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:8 PCMA/8000 a=rtpmap:100 telephone-event/8000 a=fmtp:100 0-15 a=sqn: 0 a=cdsc: 1 image udptl t38 a=sendrecv a=ptime:20 000608: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog 000609: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x498F0D80) with key=[904] to tae 000610: Apr 10 14:47:34.061 UTC: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization: Entry... 000611: Apr 10 14:47:34.061 UTC: //-1/000000000000/SIP/Info/ccsip_offer_ans_init: 000612: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.224.150.7,0 000613: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop() 000614: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address() 000615: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.249.64.50 000616: Apr 10 14:47:34.061 UTC: //-1/7753FB6B846E/SIP/State/sipSPIChangeState: 0x498F0D80 : State change from (STATE_NONE, SUBSTAT) 000617: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.224.150.7,0 000618: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT 000619: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.224.150.7,0 000620: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop() 000621: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address() 000622: Apr 10 14:47:34.061 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.249.64.50 000623: Apr 10 14:47:34.065 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckIpip: VOIP dialpeer (peer=0x46C5C504) found for sip_user: 226 000624: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done 000625: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIUpdateIdentity: SIP->PSTN: Setting Calling Number to 22588700 000626: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done 000627: Apr 10 14:47:34.065 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetPrivacy: No valid Privacy found 000628: Apr 10 14:47:34.065 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container 000629: Apr 10 14:47:34.065 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCSTA: No CSTA found in inbound container 000630: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table. 000631: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x498F0D80 key=BW1747338601006 000632: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id 000633: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 224906 000634: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 22588700 000635: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name , number 2258876 000636: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:10.224.150.7:5060, Host:10.2247 000637: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 220 000638: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found 000639: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error 000640: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID 000641: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/ccsip_validate_and_update_calling_info: PAI/PPI not configuredi for thia 000642: Apr 10 14:47:34.065 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIUpdateCallingInfoUsingRpidOrFrom: Updating Calling Info with FROMa 000643: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIGetCallConfig: Peer tag 20 matched for incoming call 000644: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPICheckReliableProvStringtag: Unable to access supported header vals 000645: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header 000646: Apr 10 14:47:34.069 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop() 000647: Apr 10 14:47:34.069 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address() 000648: Apr 10 14:47:34.069 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.249.64.50 000649: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPICheckReliableProvStringtag: Unable to access supported header vals 000650: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header 000651: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled 000652: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH 000653: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled 000654: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH 000655: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1 and offer-all is E 000656: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled 000657: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0 000658: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIGetCallConfig: Media forking disabled 000659: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Truk 000660: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0 000661: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0 000662: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist d 000663: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIContinueNewMsgInvite: Calling name , number 22588700, Calling oct0 000664: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NE 000665: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPICheckReliableProvStringtag: Unable to access supported header vals 000666: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIValidateRequestUri: Not Enabled 000667: Apr 10 14:47:34.069 UTC: //-1/7753FB6B846E/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0 000668: Apr 10 14:47:34.069 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_IsSDPPassthruEnabled: - 0 000669: Apr 10 14:47:34.069 UTC: //904/7753FB6B846E/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ 000670: Apr 10 14:47:34.069 UTC: //904/7753FB6B846E/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:0, container:0 000671: Apr 10 14:47:34.069 UTC: //904/7753FB6B846E/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr: Session-Expires value: 1800 refresher: none 000672: Apr 10 14:47:34.069 UTC: //904/7753FB6B846E/SIP/Info/Session-Timer/sipSTSLExtractMinSEHdr: Min-SE Duration: 600 000673: Apr 10 14:47:34.069 UTC: //904/7753FB6B846E/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ 000674: Apr 10 14:47:34.069 UTC: //904/7753FB6B846E/SIP/Info/Session-Timer/sipSTSLInitialSRReqPeerEventGen: sending received sessiog 000675: Apr 10 14:47:34.069 UTC: //904/7753FB6B846E/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_PASS_ST_PAR0 000676: Apr 10 14:47:34.069 UTC: //904/7753FB6B846E/SIP/Info/Session-Timer/sipSTSLMain: SE: 1800;refresher:none peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:1800, Configured Min-SE:1800 000677: Apr 10 14:47:34.069 UTC: //904/7753FB6B846E/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container 000678: Apr 10 14:47:34.069 UTC: //904/7753FB6B846E/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app contr 000679: Apr 10 14:47:34.069 UTC: //904/7753FB6B846E/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found 000680: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1 000681: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 24620 SIP: (904) Attribute mid, level 1 instance 1 not found. 000682: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop() 000683: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address() 000684: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 10.249.64.50 000685: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.249.64.50 000686: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(100) reserved for codec No Co 000687: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96 000688: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(100) could not be reserved as its in use by other codec No Codec 000689: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (100) is reserved by ano 000690: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 000691: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 100 000692: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for C 000693: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Media/sipSPISelectCodecVersion: g729r8 flavor of g729 codec will be used 000694: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Info/sipSPIDoAudioNegotiation: Codec (g729r8) Negotiation Successful on Sta1 000695: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20 000696: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g729r8 ptime :20, codecbyt0 000697: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729r8 codecbytes :20, pti0 000698: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negot8 000699: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0 000700: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1 000701: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(100) reserved for codec 000702: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(100) reserved for codec 000703: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101 000704: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the payload type 100 for RTP-NTE 000705: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option 000706: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in. 000707: Apr 10 14:47:34.073 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload =0 000708: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modemy 000709: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or mult0 000710: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1 payload_type=18, codec_bytes=20, codec=g729r8, dtmf_relay=rtp-nte stream_type=voice+dtmf (1), dest_ip_address=10.224.149.68, dest_port=24620 000711: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (S 000712: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Media/sipSPIUpdCallWithSdpInfo: Preferred Codec : g711alaw, bytes :160 Preferred DTMF relay : rtp-nte Preferred NTE payload : 100 Early Media : No Delayed Media : No Bridge Done : No New Media : No DSP DNLD Reqd : No 000713: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing sor 000714: Apr 10 14:47:34.073 UTC: //904/7753FB6B846E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.249.64.50 000715: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_report_media_to_peer: callId 904 peer 0 flags 0x201 state STATE_IDLE 000716: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_vcc_ProcessXcoderNeeded: xcoder_attached not yet initialis. 000717: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_report_media_to_peer: Xcoder not yet used for the call 000718: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: CallID 904, Peer CallID 0, sdp 0x49B2D69C channels 0x498F231C 000719: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/copy_channels: callId 904 size 0 ptr 0x49903344) 000720: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: CCB t38 version 0 ipip_caps version 0 000721: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: CCB fax rate 2 ipip_caps rate 7200 000722: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: stream_callid = 904 000723: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: reset the switch.. 000724: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Hndl ptype 18 mline 1 000725: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Media/sipSPISelectCodecVersion: g729r8 flavor of g729 codec will be used 000726: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g729r8 000727: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/codec_found: Codec to be matched: 16 000728: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/codec_found: codecs[i] = 16 & codec = 16 are same.. 000729: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 16 000730: Apr 10 14:47:34.077 UTC: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729r8 codecbytes :20, pti0 000731: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->n1 000732: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: failed to update call entry 000733: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Adding codec 16 ptype 18 time 20, bytes 20 as channel 0 mline 1 ss 1 10.224.149.68:24620 000734: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Hndl ptype 8 mline 1 000735: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711alaw 000736: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/codec_found: Codec to be matched: 6 000737: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/codec_found: codecs[i] = 6 & codec = 6 are same.. 000738: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 6 000739: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation NOT done, get p1 000740: Apr 10 14:47:34.077 UTC: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711alaw ptime :20, codecb0 000741: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: failed to update call entry 000742: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Adding codec 6 ptype 8 time 20, bytes 160 as channel 1 mline 1 ss 1 10.224.149.68:24620 000743: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Hndl ptype 100 mline 1 000744: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: setting ipip_caps DTMF to RFC28336 000745: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC 6 000746: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC 6 000747: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC 1 000748: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_report_media_to_peer: callId 904 flags 0x10000100 state STATE_IDLE 000749: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_report_media_to_peer: Report initial call media 000750: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0xC, ccb->pld.flags_ipip 1 000751: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/copy_channels: callId 904 size 468 ptr 0x489ED604) 000752: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_report_media_to_peer: CCSIP: Unable to report channel ind 000753: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/ccsip_update_srtp_caps: 7419: Posting Remote SRTP caps to other calll. 000754: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_report_media_to_peer: do cc_api_caps_ind() 000755: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Media/sipSPIUpdCallWithSdpInfo: Stream type : voice+dtmf Media line : 1 State : STREAM_ADDING (2) Stream address type : 1 Callid : 904 Negotiated Codec : g729r8, bytes :20 Nego. Codec payload : 18 (tx), 18 (rx) Negotiated DTMF relay : rtp-nte Negotiated NTE payload : 100 (tx), 100 (rx) Negotiated CN payload : 0 Media Srce Addr/Port : [10.249.64.50]:0 Media Dest Addr/Port : [10.224.149.68]:24620 000756: Apr 10 14:47:34.077 UTC: //904/7753FB6B846E/SIP/Info/sipSPIHandleInviteMedia: Negotiated Codec : g729r8, bytes :20 Preferred Codec : g711alaw, bytes :160 Preferred DTMF relay 1 : 6 Preferred DTMF relay 2 : 0 Negotiated DTMF relay : 6 Preferred and Negotiated NTE payloads: 100 100 Preferred and Negotiated NSE payloads: 98 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 000757: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1 000758: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort 000759: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active 000760: Apr 10 14:47:34.081 UTC: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 17362 for stream 1 000761: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port2 000762: Apr 10 14:47:34.081 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for 1 000763: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 17362 000764: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: SIP update src sdp, negoitated codec 16, payload type 18 000765: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Negotiated method of dtmf relayand pyl0 000766: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: max_event 16 000767: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = BW1747338600 000768: Apr 10 14:47:34.081 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container 000769: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found 000770: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0 000771: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Unsupported he 000772: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled: - 0 000773: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Nd 000774: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/ccsip_api_call_setup_ind: Unable to add unsupp headers to container 000775: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/ccsip_api_call_setup_ind: Set Protocol information 000776: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service 000777: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured 000778: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo 000779: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPI_ipip_store_channel_info: dtmf negotiation done, storing negotia, 000780: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPIShrlCall: Check peer: 20 for Shared-Line call, callid: 904 000781: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/ccsip_set_bearer_capability: Bearer Capability: Speech (0x00) 000782: Apr 10 14:47:34.081 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container 000783: Apr 10 14:47:34.081 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container 000784: Apr 10 14:47:34.081 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message 000785: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCS 000786: Apr 10 14:47:34.081 UTC: //904/7753FB6B846E/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 388 to table 000787: Apr 10 14:47:34.085 UTC: //904/7753FB6B846E/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP 000788: Apr 10 14:47:34.085 UTC: //904/7753FB6B846E/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:100, containe8 000789: Apr 10 14:47:34.085 UTC: //904/7753FB6B846E/SIP/Info/Session-Timer/sipSTSLValidateSessRefreshMsg: Ignoring 1xx response forg 000790: Apr 10 14:47:34.085 UTC: //904/7753FB6B846E/SIP/Info/sipSPISendInviteResponse: Associated container=0x49C7E3E8 to Invite Re0 000791: Apr 10 14:47:34.085 UTC: //904/7753FB6B846E/SIP/Transport/sipSPITransportSendMessage: msg=0x48EB13B0, addr=10.224.150.7, po0 000792: Apr 10 14:47:34.085 UTC: //904/7753FB6B846E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediatey 000793: Apr 10 14:47:34.085 UTC: //904/7753FB6B846E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 000794: Apr 10 14:47:34.085 UTC: //904/7753FB6B846E/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x48EB13B0 to defau0 000795: Apr 10 14:47:34.085 UTC: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:1: 000796: Apr 10 14:47:34.085 UTC: //904/7753FB6B846E/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x48E0 000797: Apr 10 14:47:34.085 UTC: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x48EB13B0, addrP 000798: Apr 10 14:47:34.085 UTC: //904/7753FB6B846E/SIP/State/sipSPIChangeState: 0x498F0D80 : State change from (STATE_IDLE, SUBSTA) 000799: Apr 10 14:47:34.085 UTC: //904/7753FB6B846E/SIP/Info/sipSPIProcessContactInfo: Previous Hop 10.224.150.7:5060 000800: Apr 10 14:47:34.085 UTC: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDG 000801: Apr 10 14:47:34.089 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x498EB5B8) with key=[905] to tae 000802: Apr 10 14:47:34.089 UTC: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization: Entry... 000803: Apr 10 14:47:34.089 UTC: //-1/000000000000/SIP/Info/ccsip_offer_ans_init: 000804: Apr 10 14:47:34.089 UTC: //905/000000000000/SIP/State/sipSPIChangeState: 0x498EB5B8 : State change from (STATE_NONE, SUBSTA) 000805: Apr 10 14:47:34.089 UTC: //905/000000000000/SIP/Info/ccsip_call_setup_request: Set Protocol information 000806: Apr 10 14:47:34.089 UTC: //905/000000000000/SIP/Info/ccsip_call_setup_request: Before processing SETUP REQccb->pld.flags_ip0 000807: Apr 10 14:47:34.089 UTC: //905/000000000000/SIP/Info/ccsip_call_setup_request: This a IPIP call: Chan 0, codec 16 channel 24620, ip 10.224.149.68:24620 params 0x49CAF964 caps 0x48EFA340 000808: Apr 10 14:47:34.089 UTC: //905/000000000000/SIP/Info/ccsip_call_setup_request: This a IPIP call: Chan 1, codec 6 channel 24620, ip 10.224.149.68:24620 params 0x49CAF964 caps 0x48EFA340 000809: Apr 10 14:47:34.089 UTC: //905/000000000000/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP 000810: Apr 10 14:47:34.089 UTC: //905/000000000000/SIP/Info/ccsip_call_setup_request: After processing SETUP REQccb->pld.flags_ipi0 a=fmtp:18 annexb=yes a=rtpmap:8 PCMA/8000 a=rtpmap:100 X-NSE/8000 a=fmtp:100 192-194,200-202 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=X-sqn:0 a=X-cap: 1 audio RTP/AVP 100 a=X-cpar: a=rtpmap:100 X-NSE/8000 a=X-cpar: a=fmtp:100 192-194,200-202 a=X-cap: 2 image udptl t38 000951: Apr 10 14:47:34.610 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT SIP: (905) Group (a= group line) attribute, level 65535 instance 1 not found. 000952: Apr 10 14:47:34.610 UTC: //905/7753FB6B846E/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat 000953: Apr 10 14:47:34.610 UTC: //905/7753FB6B846E/SIP/Info/sipSPISendInvite: Associated container=0x49C7D578 to Invite 000954: Apr 10 14:47:34.610 UTC: //905/7753FB6B846E/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer 000955: Apr 10 14:47:34.610 UTC: //905/7753FB6B846E/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration,E 000956: Apr 10 14:47:34.610 UTC: //905/7753FB6B846E/SIP/Transport/sipSPITransportSendMessage: msg=0x49E5DDFC, addr=10.224.150.7, po0 000957: Apr 10 14:47:34.610 UTC: //905/7753FB6B846E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediatey 000958: Apr 10 14:47:34.610 UTC: //905/7753FB6B846E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 000959: Apr 10 14:47:34.610 UTC: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:12 000960: Apr 10 14:47:34.610 UTC: //905/7753FB6B846E/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x49E5DDFC 000961: Apr 10 14:47:34.610 UTC: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x49E5DDFC, addrP 000962: Apr 10 14:47:34.610 UTC: //905/7753FB6B846E/SIP/Msg/ccsipDisplayMsg: Sent: INVITE sip:22490326@192.168.38.11:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.38.252:5060;branch=z9hG4bK271C29 From: ;tag=D8FE64-473 To: Date: Mon, 10 Apr 2017 14:47:34 GMT Call-ID: 7759796B-1D3311E7-8474C183-995196B2@192.168.38.252 Supported: 100rel,timer,resource-priority,replaces,sdp-anat Min-SE: 1800 Cisco-Guid: 2001992555-0489886183-2221851011-2572261042 User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 101 INVITE Timestamp: 1491835654 Contact: Expires: 180 Allow-Events: kpml, telephone-event Max-Forwards: 17 Session-Expires: 1800 Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 488 v=0 o=CiscoSystemsSIP-GW-UserAgent 3878 9210 IN IP4 192.168.38.252 s=SIP Call c=IN IP4 192.168.38.252 t=0 0 m=audio 17872 RTP/AVP 18 8 100 101 c=IN IP4 192.168.38.252 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=yes a=rtpmap:8 PCMA/8000 a=rtpmap:100 X-NSE/8000 a=fmtp:100 192-194,200-202 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=X-sqn:0 a=X-cap: 1 audio RTP/AVP 100 a=X-cpar: a=rtpmap:100 X-NSE/8000 a=X-cpar: a=fmtp:100 192-194,200-202 a=X-cap: 2 image udptl t38 000963: Apr 10 14:47:35.610 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT SIP: (905) Group (a= group line) attribute, level 65535 instance 1 not found. 000964: Apr 10 14:47:35.610 UTC: //905/7753FB6B846E/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat 000965: Apr 10 14:47:35.610 UTC: //905/7753FB6B846E/SIP/Info/sipSPISendInvite: Associated container=0x49C7D578 to Invite 000966: Apr 10 14:47:35.610 UTC: //905/7753FB6B846E/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer 000967: Apr 10 14:47:35.610 UTC: //905/7753FB6B846E/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration,E 000968: Apr 10 14:47:35.610 UTC: //905/7753FB6B846E/SIP/Transport/sipSPITransportSendMessage: msg=0x49E5DDFC, addr=10.224.150.7, po0 000969: Apr 10 14:47:35.610 UTC: //905/7753FB6B846E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediatey 000970: Apr 10 14:47:35.610 UTC: //905/7753FB6B846E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 000971: Apr 10 14:47:35.610 UTC: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:12 000972: Apr 10 14:47:35.610 UTC: //905/7753FB6B846E/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x49E5DDFC 000973: Apr 10 14:47:35.610 UTC: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x49E5DDFC, addrP 000974: Apr 10 14:47:35.610 UTC: //905/7753FB6B846E/SIP/Msg/ccsipDisplayMsg: Sent: INVITE sip:22490326@192.168.38.11:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.38.252:5060;branch=z9hG4bK271C29 From: ;tag=D8FE64-473 To: Date: Mon, 10 Apr 2017 14:47:35 GMT Call-ID: 7759796B-1D3311E7-8474C183-995196B2@192.168.38.252 Supported: 100rel,timer,resource-priority,replaces,sdp-anat Min-SE: 1800 Cisco-Guid: 2001992555-0489886183-2221851011-2572261042 User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 101 INVITE Timestamp: 1491835655 Contact: Expires: 180 Allow-Events: kpml, telephone-event Max-Forwards: 17 Session-Expires: 1800 Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 488 v=0 o=CiscoSystemsSIP-GW-UserAgent 3878 9210 IN IP4 192.168.38.252 s=SIP Call c=IN IP4 192.168.38.252 t=0 0 m=audio 17872 RTP/AVP 18 8 100 101 c=IN IP4 192.168.38.252 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=yes a=rtpmap:8 PCMA/8000 a=rtpmap:100 X-NSE/8000 a=fmtp:100 192-194,200-202 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=X-sqn:0 a=X-cap: 1 audio RTP/AVP 100 a=X-cpar: a=rtpmap:100 X-NSE/8000 a=X-cpar: a=fmtp:100 192-194,200-202 a=X-cap: 2 image udptl t38 000975: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Error/act_sentinvite_wait_100: Out of retries 000976: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Info/ccsip_set_cc_cause_for_spi_err: Categorized cause:102, category:129 000977: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Info/ccsip_set_release_source_for_peer: ownCallId[905], src[6] 000978: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Info/sipSPIInitiateDisconnect: Initiate call disconnect(102) for outgoing cl 000979: Apr 10 14:47:37.610 UTC: //-1/xxxxxxxxxxxx/SIP/Error/sipSPIGetContentQSIG: No Inbound Container Created !!! 000980: Apr 10 14:47:37.610 UTC: //-1/xxxxxxxxxxxx/SIP/Error/sipSPIGetContentQ931: No Inbound Container Created !!! 000981: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service 000982: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured 000983: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Error/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Invalid CCB/Data/r 000984: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Info/sipAddSipContainerToCallEntry: Unable to add passthru hdrs to container 000985: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/State/sipSPIChangeState: 0x498EB5B8 : State change from (STATE_SENT_INVITE,) 000986: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Info/ccsip_call_statistics: Requesting stats for callid=905 000987: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Info/ccsip_call_statistics: Stats request failed for callid=905, dstCallID=7 000988: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service 000989: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured 000990: Apr 10 14:47:37.610 UTC: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNT 000991: Apr 10 14:47:37.610 UTC: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 fo8 000992: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SPI_EVENT 000993: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Info/Session-Timer/sipSTSLMain: SE: 1800;refresher:none peer refresher:none, flags:2020, posted event:E_STSL_PASS_ST_PARAMS, reason:4 Configured SE:1800, Configured Min-SE:1800 000994: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Info/sipSPIIcpifUpdate: CallState: 2 Playout: 0 DiscTime:1422440 ConnTime 0 000995: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Media/sipSPIDestroyRtpSession: stream:49EC88D0 000996: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/State/sipSPIChangeState: 0x498EB5B8 : State change from (STATE_DISCONNECTIN) 000997: Apr 10 14:47:37.610 UTC: //905/7753FB6B846E/SIP/Call/sipSPICallInfo: The Call Setup Information is: Call Control Block (CCB) : 0x498EB5B8 State of The Call : STATE_DEAD TCP Sockets Used : NO Calling Number : 22588700 Called Number : 22490326 Source IP Address (Sig ): 192.168.38.252 Destn SIP Req Addr:Port : 10.224.150.7:5060 Destn SIP Resp Addr:Port : 10.224.150.7:5060 Destination Name : trunk.cyta.com.cy 000998: Apr 10 14:47:37.614 UTC: //905/7753FB6B846E/SIP/Call/sipSPIMediaCallInfo: Number of Media Streams: 1 Media Stream : 1 Negotiated Codec : No Codec Negotiated Codec Bytes : 0 Nego. Codec payload : 255 (tx), 255 (rx) Negotiated Dtmf-relay : 0 Dtmf-relay Payload : 0 (tx), 0 (rx) Source IP Address (Media): 192.168.38.252 Source IP Port (Media): 17872 Destn IP Address (Media): - Destn IP Port (Media): 0 Orig Destn IP Address:Port (Media): [ - ]:0 000999: Apr 10 14:47:37.614 UTC: //905/7753FB6B846E/SIP/Call/sipSPICallInfo: Disconnect Cause (CC) : 102 Disconnect Cause (SIP) : 200 001000: Apr 10 14:47:37.614 UTC: //905/7753FB6B846E/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 389 001001: Apr 10 14:47:37.614 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[905] removed. 001002: Apr 10 14:47:37.614 UTC: //905/7753FB6B846E/SIP/Info/sipSPIUdeleteCcbFromUACTable: ****Deleting from UAC table. 001003: Apr 10 14:47:37.614 UTC: //905/7753FB6B846E/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x498EB5B8 key=7752 001004: Apr 10 14:47:37.614 UTC: //905/7753FB6B846E/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue d 001005: Apr 10 14:47:37.614 UTC: //905/7753FB6B846E/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed 001006: Apr 10 14:47:37.614 UTC: //905/7753FB6B846E/SIP/Info/ccsip_offer_ans_delete: 001007: Apr 10 14:47:37.614 UTC: //905/7753FB6B846E/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 498EB5B8 001008: Apr 10 14:47:37.614 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[905] 001009: Apr 10 14:47:37.614 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x498EB5B8) with key=[906] to tae 001010: Apr 10 14:47:37.614 UTC: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization: Entry... 001011: Apr 10 14:47:37.614 UTC: //-1/000000000000/SIP/Info/ccsip_offer_ans_init: 001012: Apr 10 14:47:37.614 UTC: //906/000000000000/SIP/State/sipSPIChangeState: 0x498EB5B8 : State change from (STATE_NONE, SUBSTA) 001013: Apr 10 14:47:37.614 UTC: //906/000000000000/SIP/Info/ccsip_call_setup_request: Set Protocol information 001014: Apr 10 14:47:37.614 UTC: //906/000000000000/SIP/Info/ccsip_call_setup_request: Before processing SETUP REQccb->pld.flags_ip0 001015: Apr 10 14:47:37.614 UTC: //906/000000000000/SIP/Info/ccsip_call_setup_request: This a IPIP call: Chan 0, codec 16 channel 24620, ip 10.224.149.68:24620 params 0x49CAF964 caps 0x48EFA340 001016: Apr 10 14:47:37.614 UTC: //906/000000000000/SIP/Info/ccsip_call_setup_request: This a IPIP call: Chan 1, codec 6 channel 24620, ip 10.224.149.68:24620 params 0x49CAF964 caps 0x48EFA340 001017: Apr 10 14:47:37.614 UTC: //906/000000000000/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP 001018: Apr 10 14:47:37.614 UTC: //906/000000000000/SIP/Info/ccsip_call_setup_request: After processing SETUP REQccb->pld.flags_ipi0 001019: Apr 10 14:47:37.618 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : trunk.cyt0 001020: Apr 10 14:47:37.618 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: outbound_host : trunk.c0 001021: Apr 10 14:47:37.618 UTC: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_SETUP 001022: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/ccsip_call_setup_request: Incrementing call counter to [1] in dial-pee] 001023: Apr 10 14:47:37.618 UTC: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 174) 001024: Apr 10 14:47:37.618 UTC: //904/7753FB6B846E/SIP/Info/ccsip_event_handler: ccsip_event_handler: peer ID 906 chans 0x49DC12D0 event 174 flags 0x40001C 0x10000100 0x400403 data 0x49DC12D0 001025: Apr 10 14:47:37.618 UTC: //904/7753FB6B846E/SIP/Info/ccsip_event_handler: ccsip_event_handler: CC_EV_H245_SET_MODE: peer ID 906 chans 0x49DC12D0 event 174 flags 0x40001C 0x10000100 0x400403 data 0x49DC12D1 001026: Apr 10 14:47:37.618 UTC: //904/7753FB6B846E/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP 001027: Apr 10 14:47:37.618 UTC: //904/7753FB6B846E/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SET_MODE 001028: Apr 10 14:47:37.618 UTC: //904/7753FB6B846E/SIP/Info/Session-Timer/sipSTSLMain: SE: 1800;refresher:none peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:1800, Configured Min-SE:1800 001029: Apr 10 14:47:37.618 UTC: //904/7753FB6B846E/SIP/Info/ccsip_event_handler: Changing the flow mode due to SET_MODE 001030: Apr 10 14:47:37.618 UTC: //904/7753FB6B846E/SIP/Info/sipSPIHandleMediaFlowModeChange: 001031: Apr 10 14:47:37.618 UTC: //904/7753FB6B846E/SIP/Info/sipSPIHandleMediaFlowModeChange: current media flow mode is 1, desired1 001032: Apr 10 14:47:37.618 UTC: //904/7753FB6B846E/SIP/Info/sipSPIHandleMediaFlowModeChange: current flow mode is same as desired e 001033: Apr 10 14:47:37.618 UTC: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED 001034: Apr 10 14:47:37.618 UTC: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 fo2 001035: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 38A to table 001036: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPIGetCallConfig: preferred_codec set[0] type :No Codec bytes: 0 001037: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPIGetCallConfig: Media forking disabled 001038: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled 001039: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active 001040: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH 001041: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled 001042: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH 001043: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1 and offer-all isE 001044: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled 001045: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=904 001046: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPIGetCallConfig: Media forking disabled 001047: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trk 001048: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0 001049: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0 001050: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylistd 001051: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/preprocessSetup: This is a not a SIGO Call -, could be DM call 001052: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_peer_channelInfo_to_sdp: Valid peer channels availabl! 001053: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_peer_channelInfo_to_sdp: No video caps posted by peer 001054: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: callid 906, channels 0x48F03E7C caps 0x48EFA340 001055: Apr 10 14:47:37.618 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: Peer cap provided: callid = 906, 0 001056: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPIDtmfTranscoder: Return upon SCCP version 0 001057: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPISrtpTranscoder: Checking if transcoder is needed for SRTP-RTP 001058: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPIAudioLevelAdjustmentTranscoder: Entry.. 001059: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPIAudioLevelAdjustmentTranscoder: AudioLevelAdjustment do not needr 001060: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_codec_byte_transrating: codec class not supported in xratiE 001061: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPICodecTranscoder: No body else needs xcoder. OFFER_ALL is intact 001062: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_vcc_CheckVoiceClassCodecConfiguration: Either one of the c. 001063: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_vcc_CheckCodecSetType: Check between Equalset & Subset.. 001064: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/codec_found: Codec to be matched: 16 001065: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/codec_found: codecs[i] = 16 & codec = 16 are same.. 001066: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_vcc_CheckCodecSetType: Match found.. continue for next cod. 001067: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/codec_found: Codec to be matched: 6 001068: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/codec_found: codecs[i] = 6 & codec = 6 are same.. 001069: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_vcc_CheckCodecSetType: Match found.. continue for next cod. 001070: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_vcc_CheckCodecSetType: This is Subset 001071: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPICodecTranscoder: Static codec or Equalset or Subset w/o offer-al. 001072: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/codec_found: Codec to be matched: 16 001073: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/codec_found: codecs[i] = 16 & codec = 16 are same.. 001074: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/codec_found: Codec to be matched: 6 001075: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/codec_found: codecs[i] = 6 & codec = 6 are same.. 001076: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPIUpdatePreferredCodec: num_chans = 2 001077: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPICheckAndReserveTranscoder: Xcoder is not needed 001078: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPISrtpTranscoder: Checking if transcoder is needed for SRTP-RTP 001079: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_setOptionTagInfo: Option Tag Rel1xx value is 0 001080: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sip_gw_pre_setup_add_sdp_container: DNS/ENUM resolution required; DefeP 001081: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPIAddMLPPServicesInfo: No MLP Info available on incoming leg 001082: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPIPreprocessUriFormat: Url cfg for 1: 2,phone-ctxt=FALSE 001083: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPIAddCiscoGcid: Gcid value not set - not adding header. 001084: Apr 10 14:47:37.622 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddPrivacyandIdentityInfo: ccb->local_host_name,ccb->src_addr_strL 001085: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPICompareHistoryInfoWithMatchedDialpeer: call-route history-info Cd 001086: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Error/sipSPI_ipip_set_history_info_header: ccb->src_addr_str is NULL 001087: Apr 10 14:47:37.622 UTC: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_DNS_RESOLVE 001088: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/State/sipSPIChangeState: 0x498EB5B8 : State change from (STATE_IDLE, SUBSTA) 001089: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/State/sipSPIChangeState: 0x498EB5B8 : State change from (STATE_IDLE, SUBSTA) 001090: Apr 10 14:47:37.622 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop() 001091: Apr 10 14:47:37.622 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address() 001092: Apr 10 14:47:37.622 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.249.64.50 001093: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPIUaddCcbToUACTable: ****Adding to UAC table. 001094: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x498EB5B8 key=79734A52-1D330 001095: Apr 10 14:47:37.622 UTC: //906/7753FB6B846E/SIP/Info/sipSPIUsetBillingProfile: sipCallId for billing records = 79734A52-1D30 001096: Apr 10 14:47:37.622 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_aaaa_query: DNS query for trunk.cyta.com.cy and type:1 001097: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_query: TYPE A query successful for trunk.cyta.com.cy 001098: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_aaaa_query: IP Address of trunk.cyta.com.cy is: 001099: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_aaaa_query: 10.224.150.7 001100: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 fo5 001101: Apr 10 14:47:37.626 UTC: //906/7753FB6B846E/SIP/State/sipSPIChangeState: 0x498EB5B8 : State change from (STATE_IDLE, SUBSTA) 001102: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICacheHostToCCB: sipSPICacheHostToCCB dnsResponse.num_hosts = 1 001103: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICacheHostToCCB: IP Address No. 1, IP address 10.224.150.7 001104: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop() 001105: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address() 001106: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.249.64.50 001107: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop() 001108: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address() 001109: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.249.64.50 001110: Apr 10 14:47:37.626 UTC: //906/7753FB6B846E/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0 001111: Apr 10 14:47:37.626 UTC: //906/7753FB6B846E/SIP/Info/sipSPICompareHistoryInfoWithMatchedDialpeer: call-route history-info Cd 001112: Apr 10 14:47:37.626 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_set_history_info_header: No HI header recvd from container 001113: Apr 10 14:47:37.626 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_set_diversion_header: No diversion header recvd from contar 001114: Apr 10 14:47:37.626 UTC: //906/7753FB6B846E/SIP/Info/sipSPIAddPrivacyandIdentityInfo: Removing "id" value from Privacy 001115: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop() 001116: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address() 001117: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 10.249.64.50 001118: Apr 10 14:47:37.626 UTC: //906/7753FB6B846E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.249.64.50 001119: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop() 001120: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address() 001121: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.249.64.50 001122: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 17776 for stream 1 001123: Apr 10 14:47:37.626 UTC: //906/7753FB6B846E/SIP/Media/sipSPIAddSDPMediaPayload: Preferred method of dtmf relay is: 6, with 1 001124: Apr 10 14:47:37.626 UTC: //906/7753FB6B846E/SIP/Info/sipSPIAddSDPPayloadAttributes: max_event 15 001125: Apr 10 14:47:37.626 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for 1 001126: Apr 10 14:47:37.626 UTC: //906/7753FB6B846E/SIP/Info/sipSPIOutgoingCallSDP: Creating recv-only stream for outbound call 001127: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Media/sipSPIProcessRtpSessions: No active streams. 001128: Apr 10 14:47:37.630 UTC: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.224.150.7,0 001129: Apr 10 14:47:37.630 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT 001130: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ 001131: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:0, container:8 001132: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ 001133: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_PASS_ST_PAR0 001134: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Info/Session-Timer/sipSTSLSRReqPassPeerEventHndlr: session timer negotiatedd 001135: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Info/Session-Timer/sipSTSLMain: SE: 1800;refresher:none peer refresher:none, flags:2020, posted event:E_STSL_PASS_ST_PARAMS, reason:4 Configured SE:1800, Configured Min-SE:1800 001136: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 0 event 001137: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get anyr 001138: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get anyr 001139: Apr 10 14:47:37.630 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIgetRegistrarHost: registrar host retrieved : trunk.cyta.com.cy SIP: (906) Group (a= group line) attribute, level 65535 instance 1 not found. 001140: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat 001141: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Info/sipSPISendInvite: Associated container=0x49C7D6D8 to Invite 001142: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer 001143: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, SwE 001144: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Transport/sipSPITransportSendMessage: msg=0x49DB11A0, addr=10.224.150.7, poC 001145: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediatey 001146: Apr 10 14:47:37.630 UTC: //906/7753FB6B846E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 001147: Apr 10 14:47:37.630 UTC: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:1: 001148: Apr 10 14:47:37.634 UTC: //906/7753FB6B846E/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x49DB11A0 001149: Apr 10 14:47:37.634 UTC: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x49DB11A0, addrP 001150: Apr 10 14:47:37.634 UTC: //906/7753FB6B846E/SIP/Info/sentInviteRequest: Sent Invite in state STATE_IDLE 001151: Apr 10 14:47:37.634 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sentInviteRequest: Transaction active. Facilities will be queued. 001152: Apr 10 14:47:37.634 UTC: //906/7753FB6B846E/SIP/State/sipSPIChangeState: 0x498EB5B8 : State change from (STATE_IDLE, SUBSTA) 001153: Apr 10 14:47:37.634 UTC: //906/7753FB6B846E/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 906) to ty 001154: Apr 10 14:47:37.634 UTC: //906/7753FB6B846E/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing sor 001155: Apr 10 14:47:37.634 UTC: //906/7753FB6B846E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.249.64.50 001156: Apr 10 14:47:37.634 UTC: //906/7753FB6B846E/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1 001157: Apr 10 14:47:37.634 UTC: //906/7753FB6B846E/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info laddr = 10.249.64.50, lport = 17776, raddr = 0.0.0.0, rport=0, do_rtcp=FALSE src_callid = 906, dest_callid = -1, stream type = voice+dtmf, stream direction = RECVONLY media_ip_addr = - , vrf tableid = 0 media_addr_type = 1 001158: Apr 10 14:47:37.634 UTC: //906/7753FB6B846E/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one 001159: Apr 10 14:47:37.634 UTC: //906/7753FB6B846E/SIP/Info/sipSPICreateRtpSession: sess: 47641EFC do_rtcp:0 001160: Apr 10 14:47:37.634 UTC: //904/7753FB6B846E/SIP/Info/ccsip_update_peer_caps: Stream is NULL 001161: Apr 10 14:47:37.634 UTC: //904/7753FB6B846E/SIP/Info/ccsip_update_peer_caps: gccb/stream is NULL, not updating now !! 001162: Apr 10 14:47:37.634 UTC: //906/7753FB6B846E/SIP/Info/sipSPIUpdateGccb: Failure from the peer leg so no updations now!! 001163: Apr 10 14:47:37.634 UTC: //906/7753FB6B846E/SIP/Media/sipSPICreateRtpSession: stun is disabled 001164: Apr 10 14:47:37.634 UTC: //906/7753FB6B846E/SIP/State/sipSPIChangeStreamState: Stream (callid = 906) State changed from ( 001165: Apr 10 14:47:37.634 UTC: //906/7753FB6B846E/SIP/Msg/ccsipDisplayMsg: Sent: INVITE sip:22490326@trunk.cyta.com.cy:5060 SIP/2.0 Via: SIP/2.0/UDP 10.249.64.50:5060;branch=z9hG4bK272641 From: ;tag=D90C28-89B To: Date: Mon, 10 Apr 2017 14:47:37 GMT Call-ID: 79734A52-1D3311E7-8476C183-995196B2@10.249.64.50 Supported: 100rel,timer,resource-priority,replaces,sdp-anat Min-SE: 1800 Cisco-Guid: 2001992555-0489886183-2221851011-2572261042 User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 101 INVITE Timestamp: 1491835657 Contact: Expires: 180 Allow-Events: telephone-event Max-Forwards: 17 Session-Expires: 1800 Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 482 v=0 o=CiscoSystemsSIP-GW-UserAgent 4431 1557 IN IP4 10.249.64.50 s=SIP Call c=IN IP4 10.249.64.50 t=0 0 m=audio 17776 RTP/AVP 18 8 100 101 c=IN IP4 10.249.64.50 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=yes a=rtpmap:8 PCMA/8000 a=rtpmap:100 X-NSE/8000 a=fmtp:100 192-194,200-202 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=X-sqn:0 a=X-cap: 1 audio RTP/AVP 100 a=X-cpar: a=rtpmap:100 X-NSE/8000 a=X-cpar: a=fmtp:100 192-194,200-202 a=X-cap: 2 image udptl t38 001166: Apr 10 14:47:37.754 UTC: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.224.15] 001167: Apr 10 14:47:37.754 UTC: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 fo1 001168: Apr 10 14:47:37.758 UTC: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0 001169: Apr 10 14:47:37.758 UTC: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog 001170: Apr 10 14:47:37.758 UTC: //906/7753FB6B846E/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.249.64.50:5060;branch=z9hG4bK272641 To: ;tag=h7g4Esbg_987387275-1491835657593 From: ;tag=D90C28-89B Call-ID: 79734A52-1D3311E7-8476C183-995196B2@10.249.64.50 CSeq: 101 INVITE Contact: Record-Route: P-Asserted-Identity: P-Early-Media: sendonly Privacy: none Content-Type: application/sdp Content-Length: 248 Session: Media Allow: ACK, BYE, CANCEL, INFO, INVITE, OPTIONS, PRACK, REFER, NOTIFY, UPDATE v=0 o=BroadWorks 772714616 1 IN IP4 10.224.150.7 s=- c=IN IP4 10.224.151.4 t=0 0 m=audio 56550 RTP/AVP 18 101 c=IN IP4 10.224.151.4 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=yes a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 001171: Apr 10 14:47:37.758 UTC: //906/7753FB6B846E/SIP/Info/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1X 001172: Apr 10 14:47:37.758 UTC: //906/7753FB6B846E/SIP/Info/ccsip_api_update_allowed: UPDATE(1) allowed 001317: Apr 10 14:47:37.874 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[904] 001318: Apr 10 14:47:41.683 UTC: //901/68CAAC4C846C/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 385 001319: Apr 10 14:47:41.683 UTC: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[901] removed. 001320: Apr 10 14:47:41.683 UTC: //901/68CAAC4C846C/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table. 001321: Apr 10 14:47:41.683 UTC: //901/68CAAC4C846C/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x498F6548 key=9191 001322: Apr 10 14:47:41.683 UTC: //901/68CAAC4C846C/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table. 001323: Apr 10 14:47:41.683 UTC: //901/68CAAC4C846C/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue d 001324: Apr 10 14:47:41.683 UTC: //901/68CAAC4C846C/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed 001325: Apr 10 14:47:41.683 UTC: //901/68CAAC4C846C/SIP/Info/ccsip_offer_ans_delete: 001326: Apr 10 14:47:41.683 UTC: //901/68CAAC4C846C/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 498F6548