Hi,<br><br>I am new to this list and facing an error.<br>I have welcome application set at 004412345678<br>If I dial that number from any cisco phones, it will play the message.<br><br>But when I dial that number (which is our DID) from outside, it does not play anything and the line is disconnected. <br>
I cannot find out why it is doing so. <br><br><br>Below are the logs for you to check.<br><br>I have modified the IPs, but rest all are intact.<br><br>If you search for "Incoming Dial-peer=44" , it will show that the DID incoming is in fact being processed by this dial-peer, but does not seem to work.<br>
<br>Please check and help me to pinpoint the issue. <br><br><br><br>changed ip addresses: <br><br>caller: 0065123456789<br>DID: 004412345678<br>sip provider: <a href="http://sipserver.com">sipserver.com</a><br>our sip username: 555555<br>
<br><br><br><br>dial-peer voice 44 voip<br> answer-address 004412345678<br> destination-pattern 004412345678<br> session protocol sipv2<br> session target ipv4:192.168.0.2<br> incoming called-number .T<br> dtmf-relay rtp-nte<br>
 no vad<br><br><br><br>cisco#sh debugging<br><br><br>CCAPI:<br>  debug voip ccapi inout is ON (filter is OFF)<br>CCSIP SPI: SIP Call Statistics tracing is enabled       (filter is OFF)<br>CCSIP SPI: SIP Call Message tracing is enabled  (filter is OFF)<br>
CCSIP SPI: SIP Call State Machine tracing is enabled    (filter is OFF)<br>CCSIP SPI: SIP Call Events tracing is enabled   (filter is OFF)<br>CCSIP SPI: SIP error debug tracing is enabled   (filter is OFF)<br>CCSIP SPI: SIP info debug tracing is enabled    (filter is OFF)<br>
CCSIP SPI: SIP media debug tracing is enabled   (filter is OFF)<br>CCSIP SPI: SIP Call preauth tracing is enabled  (filter is OFF)<br>CCSIP SPI: SIP Call transport tracing is enabled        (filter is OFF)<br>CCSIP SPI: SIP DHCP tracing is enabled  (filter is OFF)<br>
<br><br><br>cisco#term moni<br>cisco#<br>Mar 18 08:13:02.120: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [111.11.11.23]:5060, local_address:[ - ]<br>Mar 18 08:13:02.120: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1<br>
Mar 18 08:13:02.120: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x4A602534<br>Mar 18 08:13:02.120: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x4A602534, addr=111.11.11.23, port=5060, local_addr=, connid=2, transport=UDP<br>
Mar 18 08:13:02.120: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:<br>Received:<br>INVITE <a href="http://sip:5555555@22.22.22.17:5060">sip:5555555@22.22.22.17:5060</a> SIP/2.0<br>Record-Route: <sip:111.11.11.23;lr=on;ftag=as0c4d53e7><br>
Record-Route: <sip:172.20.40.1;lr=on><br>Record-Route: <sip:111.11.11.23;lr=on;ftag=as0c4d53e7><br>Via: SIP/2.0/UDP 111.11.11.23:5060;branch=z9hG4bK7919.8eeefca1.0<br>Via: SIP/2.0/UDP 172.20.40.1;branch=z9hG4bK7919.8eeefca1.0<br>
Via: SIP/2.0/UDP 111.11.11.23:5060;received=217.10.68.222;branch=z9hG4bK62007f0f<br>Via: SIP/2.0/UDP 111.10.11.135:5060;branch=z9hG4bK62007f0f;rport=5060<br>From: "0065123456789" <<a href="mailto:sip%3A0065123456789@sipserver.com">sip:0065123456789@sipserver.com</a>>;tag=as0c4d53e7<br>
To: <<a href="mailto:sip%3A004412345678@sipserver.com">sip:004412345678@sipserver.com</a>><br>Contact: <<a href="mailto:sip%3A0065123456789@111.10.57.135">sip:0065123456789@111.10.57.135</a>><br>Call-ID: <a href="mailto:51b0a1d14887a9b00a7a9dd4503a354b@sipserver.com">51b0a1d14887a9b00a7a9dd4503a354b@sipserver.com</a><br>
CSeq: 102 INVITE<br>Max-Forwards: 67<br>Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY<br>Supported: replaces<br>Content-Type: application/sdp<br>Content-Length: 447<br><br>v=0<br>o=root 4047 4047 IN IP4 111.10.11.135<br>
s=session<br>c=IN IP4 110.10.77.21<br>t=0 0<br>m=audio 43670 RTP/AVP 8 0 3 97 18 112 101<br>a=rtpmap:8 PCMA/8000<br>a=rtpmap:0 PCMU/8000<br>a=rtpmap:3 GSM/8000<br>a=rtpmap:97 iLBC/8000<br>a=fmtp:97 mode=30<br>a=rtpmap:18 G729/8000<br>
a=fmtp:18 annexb=no<br>a=rtpmap:112 G726-32/8000<br>a=rtpmap:101 telephone-event/8000<br>a=fmtp:101 0-16<br>a=silenceSupp:off - - - -<br>a=ptime:20<br>a=sendrecv<br>a=direction:active<br>a=nortpproxy:yes<br><br>Mar 18 08:13:02.120: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog<br>
Mar 18 08:13:02.120: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x4C3019A8) with key=[7086] to table<br>Mar 18 08:13:02.120: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...<br>Mar 18 08:13:02.124: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:<br>
Mar 18 08:13:02.124: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 111.11.11.23,Port 5060, Transport 1, SentBy Port 5060<br>Mar 18 08:13:02.124: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()<br>
Mar 18 08:13:02.124: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()<br>Mar 18 08:13:02.124: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 22.22.22.17<br>
Mar 18 08:13:02.124: //-1/60C4BCDF85DE/SIP/State/sipSPIChangeState: 0x4C3019A8 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)<br>Mar 18 08:13:02.124: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 111.11.11.23,Port 5060, Transport 1, SentBy Port 5060<br>
Mar 18 08:13:02.124: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT<br>Mar 18 08:13:02.124: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 111.11.11.23,Port 5060, Transport 1, SentBy Port 5060<br>
Mar 18 08:13:02.124: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()<br>Mar 18 08:13:02.124: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()<br>
Mar 18 08:13:02.128: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 22.22.22.17<br>Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done<br>Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done<br>
Mar 18 08:13:02.128: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container<br>Mar 18 08:13:02.128: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCSTA: No CSTA found in inbound container<br>Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.<br>
Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x4C3019A8 key=51b0a1d14887a9b00a7a9dd4503a354b@sipserver.com5555555<br>Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id<br>
Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 5555555<br>Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 0065123456789<br>
Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name 0065123456789, number 0065123456789, Calling oct3 0x00, oct_3a 0x80, Called number 5555555<br>Mar 18 08:13:02.132: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:<a href="http://111.11.11.23:5060">111.11.11.23:5060</a>, Host:111.11.11.23<br>
Mar 18 08:13:02.132: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 0065123456789<br>Mar 18 08:13:02.132: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found<br>
Mar 18 08:13:02.132: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error<br>Mar 18 08:13:02.132: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID<br>
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetCallConfig: Peer tag 44 matched for incoming call<br>Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header<br>
Mar 18 08:13:02.136: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()<br>Mar 18 08:13:02.136: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()<br>
Mar 18 08:13:02.136: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 22.22.22.17<br>Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header<br>
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled<br>Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH<br>Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled<br>
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH<br>Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetCallConfig: Checking Video Type Rate=-1 video_codec_allowed=1F<br>
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled<br>Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0<br>Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetCallConfig: Media forking disabled<br>
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk<br>Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0<br>
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0<br>Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled<br>
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIContinueNewMsgInvite: Calling name 0065123456789, number 0065123456789, Calling oct3 0x00, oct_3a 0x80, ext_priv 0x00, Called number 5555555, oct3 0x00<br>Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE<br>
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIValidateRequestUri: Not Enabled<br>Mar 18 08:13:02.140: //-1/60C4BCDF85DE/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0<br>Mar 18 08:13:02.140: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_IsSDPPassthruEnabled:  - 0<br>
Mar 18 08:13:02.140: //7332/60C4BCDF85DE/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ<br>Mar 18 08:13:02.140: //7332/60C4BCDF85DE/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:0, container:4E05B0E0<br>
Mar 18 08:13:02.140: //7332/60C4BCDF85DE/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr: Not received session expires header<br>Mar 18 08:13:02.140: //7332/60C4BCDF85DE/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ<br>
Mar 18 08:13:02.140: //7332/60C4BCDF85DE/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_LEG_BY_LEG, SE Value:0, SE Refresher:none, Min-SE Value:1800, flags:2000<br>Mar 18 08:13:02.140: //7332/60C4BCDF85DE/SIP/Info/Session-Timer/sipSTSLMain:<br>
        SE: 0;refresher:none peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4<br>        Configured SE:1800, Configured Min-SE:1800<br>Mar 18 08:13:02.140: //7332/60C4BCDF85DE/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container<br>
Mar 18 08:13:02.140: //7332/60C4BCDF85DE/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container<br>Mar 18 08:13:02.140: //7332/60C4BCDF85DE/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found<br>
SIP: Warning: No network type specified in comediadir attribute.<br>SIP: Warning: Unrecognized attribute (nortpproxy)<br>Mar 18 08:13:02.144: //7332/60C4BCDF85DE/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1<br>
Mar 18 08:13:02.144: //7332/60C4BCDF85DE/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 43670<br>SIP: (7332) Attribute mid, level 1 instance 1 not found.<br>Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop()<br>
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address()<br>Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 22.22.22.17<br>
Mar 18 08:13:02.144: //7332/60C4BCDF85DE/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 22.22.22.17<br>Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(97) reserved for codec ilbc<br>
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(97) could not be reserved<br>                          as its in use by other codec ilbc<br>Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (97) is  reserved by another application<br>
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 116<br>Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 97<br>
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec:<br>Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(112) reserved for codec g726r32<br>
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(112) reserved for codec g726r32<br>Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec No Codec<br>
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96<br>Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved<br>
                          as its in use by other codec No Codec<br>Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is  reserved by another application<br>Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 99<br>
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101<br>Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 99 for Codec:<br>
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/rtpAvpCodec_to_voipCodec: Dynamic Payload :97 in SDP Body<br>Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Media/sipSPISelectCodecVersion: g729r8 flavor of g729 codec will be used<br>
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPIDoAudioNegotiation: Codec (g729r8) Negotiation Successful on Static Payload for m-line 1<br>Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20<br>
Mar 18 08:13:02.148: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g729r8 ptime :20, codecbytes: 20<br>Mar 18 08:13:02.148: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729r8 codecbytes :20, ptime: 20<br>
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 20 for codec g729r8<br>Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0<br>
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1<br>Mar 18 08:13:02.148: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec<br>Mar 18 08:13:02.148: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec<br>
Mar 18 08:13:02.148: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 99<br>Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the payload type 101 for RTP-NTE<br>
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option<br>Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of full named event(NE) match in fmtp list of events.<br>
Mar 18 08:13:02.148: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0<br>Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay<br>
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPIGetSDPDirectionAttribute: Extraction of src address triggered with media direction role as: 1<br>Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1<br>
        payload_type=18, codec_bytes=20, codec=g729r8, dtmf_relay=rtp-nte<br>        stream_type=voice+dtmf (1), dest_ip_address=111.10.77.21, dest_port=43670<br>Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/State/sipSPIChangeStreamState: Stream (callid =  -1)  State changed from (STREAM_DEAD) to (STREAM_ADDING)<br>
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Media/sipSPIUpdCallWithSdpInfo:<br>        Preferred Codec        : g729r8, bytes :20<br>        Preferred  DTMF relay  : rtp-nte<br>        Preferred NTE payload  : 101<br>        Early Media            : No<br>
        Delayed Media          : No<br>        Bridge Done            : No<br>        New Media              : No<br>        DSP DNLD Reqd          : No<br><br>Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr<br>
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 22.22.22.17<br>Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_report_media_to_peer:<br> callId 7332 peer 0 flags 0x201 state STATE_IDLE<br>
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_vcc_ProcessXcoderNeeded: xcoder_attached not yet initialised for this call.<br>Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_report_media_to_peer: Xcoder not yet used for the call<br>
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:<br>CallID 7332, Peer CallID 0, sdp 0x4C1DA6B4 channels 0x4C302F44<br>Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/copy_channels:<br>
 callId 7332 size 0 ptr 0x4ACF7EDC)<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: reset the  switch..<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:<br>
Hndl ptype 8 mline 1<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711alaw<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found:<br>Codec to be matched: 6<br>
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found: No match for the codecs found..<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:<br>Hndl ptype 0 mline 1<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711ulaw<br>
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found:<br>Codec to be matched: 5<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found: No match for the codecs found..<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:<br>
Hndl ptype 3 mline 1<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec gsmfr<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found:<br>Codec to be matched: 10<br>
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found: No match for the codecs found..<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:<br>Hndl ptype 97 mline 1<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found:<br>
Codec to be matched: 33<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found: No match for the codecs found..<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:<br>Hndl ptype 18 mline 1<br>
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Media/sipSPISelectCodecVersion: g729r8 flavor of g729 codec will be used<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g729r8<br>
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found:<br>Codec to be matched: 16<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found:  codecs[i] = 16 & codec = 16 are same..<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 16<br>
<br>Mar 18 08:13:02.152: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729r8 codecbytes :20, ptime: 20<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=20,stream->negotiated_codec_bytes=20, coverted ptime=20 stream->mline_index=1, media_ndx=1<br>
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:<br>failed to update call entry<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:<br>Adding codec 16 ptype 18 time 20, bytes 20  as channel 0 mline 1 ss 0 <a href="http://111.10.77.21:43670">111.10.77.21:43670</a><br>
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:<br>Hndl ptype 112 mline 1<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found:<br>Codec to be matched: 4<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found: No match for the codecs found..<br>
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:<br>Hndl ptype 101 mline 1<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: setting ipip_caps DTMF to RFC2833: callid = 7332, dtmf = 6<br>
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 16<br><br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1<br>
<br>Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_report_media_to_peer:<br> callId 7332 flags 0x10000100 state STATE_IDLE<br>Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_report_media_to_peer:<br>
Report initial call media<br>Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0xC, ccb->pld.flags_ipip 0x201<br><br>Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/copy_channels:<br>
 callId 7332 size 240 ptr 0x4E3C5E8C)<br>Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_report_media_to_peer:<br>CCSIP: Unable to report channel ind<br>Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/ccsip_update_srtp_caps:  7421: Posting Remote SRTP caps to other callleg.<br>
Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_report_media_to_peer: do cc_api_caps_ind()<br>Mar 18 08:13:02.156: //7332/xxxxxxxxxxxx/CCAPI/cc_api_caps_ind:<br>   Call Entry Is Not Found<br>Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Media/sipSPIUpdCallWithSdpInfo:<br>
          Stream type            : voice+dtmf<br>          Media line             : 1<br>          State                  : STREAM_ADDING (2)<br>          Stream address type    : 1<br>          Callid                 : -1<br>
          Negotiated Codec       : g729r8, bytes :20<br>          Nego. Codec payload    : 18 (tx), 18 (rx)<br>          Negotiated DTMF relay  : rtp-nte<br>          Negotiated NTE payload : 101 (tx), 101 (rx)<br>          Negotiated CN payload  : 0<br>
          Media Srce Addr/Port   : [22.22.22.17]:0<br>          Media Dest Addr/Port   : [111.10.77.21]:43670<br><br>Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPIHandleInviteMedia:<br>Negotiated Codec       : g729r8, bytes :20<br>
Preferred Codec        : g729r8, bytes :20<br>Preferred  DTMF relay 1 : 6<br>Preferred  DTMF relay 2 : 0<br>Negotiated DTMF relay   : 6<br>Preferred and Negotiated NTE payloads: 101 101<br>Preferred and Negotiated NSE payloads: 100 0<br>
Preferred and Negotiated Modem Relay: 0 0<br>Preferred and Negotiated V150.1 Modem Passthrough: 0 0<br>Preferred and Negotiated V150.1 Modem Relay: 0 0<br>Preferred and Negotiated Modem Relay GwXid: 1 0<br><br>Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1<br>
Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort<br>Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active<br>Mar 18 08:13:02.156: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 18470 for stream 1<br>
Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=18470<br>Mar 18 08:13:02.156: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1<br>
Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 18470<br>Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPIUpdateSrcSdpVariablePart:<br> SIP update src sdp, negoitated codec 16, payload type 18<br>
<br>Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Negotiated method of dtmf relayand pyld: 6 101<br><br>Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPIUpdateSrcSdpVariablePart: max_event 16<br>
Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = <a href="mailto:51b0a1d14887a9b00a7a9dd4503a354b@sipserver.com">51b0a1d14887a9b00a7a9dd4503a354b@sipserver.com</a><br>
Mar 18 08:13:02.160: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container<br>Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found<br>Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0<br>
Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Error/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Unsupported header passthru is not configured and no headers are present in hdr_hash_queue<br>Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled:  - 0<br>
Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Not Enabled<br>Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Error/ccsip_api_call_setup_ind: Unable to add unsupp headers to container<br>
Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/ccsip_api_call_setup_ind: Set Protocol information<br>Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service<br>Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured<br>
Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo<br>Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_store_channel_info: dtmf negotiation done, storing negotiated dtmf = 6,<br>
Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPIShrlCall: Check peer: 44 for Shared-Line call, callid: 7332<br>Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/ccsip_set_bearer_capability:<br>   Bearer Capability: Speech (0x00)<br>
Mar 18 08:13:02.160: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container<br>Mar 18 08:13:02.160: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container<br>
Mar 18 08:13:02.160: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message<br><br>Mar 18 08:13:02.160: //-1/60C4BCDF85DE/CCAPI/cc_api_display_ie_subfields:<br>   cc_api_call_setup_ind_common:<br>
   cisco-username=0065123456789<br>   ----- ccCallInfo IE subfields -----<br>   cisco-ani=0065123456789<br>   cisco-anitype=0<br>   cisco-aniplan=0<br>   cisco-anipi=0<br>   cisco-anisi=0<br>   dest=5555555<br>   cisco-desttype=0<br>
   cisco-destplan=0<br>   cisco-rdie=FFFFFFFF<br>   cisco-rdn=<br>   cisco-rdntype=0<br>   cisco-rdnplan=0<br>   cisco-rdnpi=-1<br>   cisco-rdnsi=-1<br>   cisco-redirectreason=-1   fwd_final_type =0<br>   final_redirectNumber =<br>
   hunt_group_timeout =0<br><br>Mar 18 08:13:02.164: //-1/60C4BCDF85DE/CCAPI/cc_api_call_setup_ind_common:<br>   Interface=0x4A6056C0, Call Info(<br>   Calling Number=0065123456789,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),<br>
   Called Number=5555555(TON=Unknown, NPI=Unknown),<br>   Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,<br>   Incoming Dial-peer=44, Progress Indication=NULL(0), Calling IE Present=TRUE,<br>
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=7332<br>Mar 18 08:13:02.164: //-1/60C4BCDF85DE/CCAPI/ccCheckClipClir:<br>   In: Calling Number=0065123456789(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)<br>
Mar 18 08:13:02.164: //-1/60C4BCDF85DE/CCAPI/ccCheckClipClir:<br>   Out: Calling Number=0065123456789(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)<br>Mar 18 08:13:02.164: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:<br>
<br>Mar 18 08:13:02.164: :cc_get_feature_vsa malloc success<br>Mar 18 08:13:02.164: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:<br><br>Mar 18 08:13:02.164:  cc_get_feature_vsa count is 1<br>Mar 18 08:13:02.164: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:<br>
<br>Mar 18 08:13:02.164: :FEATURE_VSA attributes are: feature_name:0,feature_time:1222875552,feature_id:473<br>Mar 18 08:13:02.164: //7332/60C4BCDF85DE/CCAPI/cc_api_call_setup_ind_common:<br>   Set Up Event Sent;<br>   Call Info(Calling Number=0065123456789(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),<br>
   Called Number=5555555(TON=Unknown, NPI=Unknown))<br>Mar 18 08:13:02.164: //7332/60C4BCDF85DE/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS<br>Mar 18 08:13:02.164: //7332/60C4BCDF85DE/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 1CA4 to table<br>
Mar 18 08:13:02.164: //7332/60C4BCDF85DE/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP<br>Mar 18 08:13:02.164: //7332/60C4BCDF85DE/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:100, container:4E05B500<br>
Mar 18 08:13:02.164: //7332/60C4BCDF85DE/SIP/Info/Session-Timer/sipSTSLValidateSessRefreshMsg: Ignoring 1xx response for session timer processing<br>Mar 18 08:13:02.168: //7332/60C4BCDF85DE/SIP/Info/sipSPISendInviteResponse: Associated container=0x4E05B500 to Invite Response 100<br>
Mar 18 08:13:02.168: //7332/60C4BCDF85DE/SIP/Transport/sipSPITransportSendMessage: msg=0x4BA15A08, addr=111.11.11.23, port=5060, sentBy_port=5060, local_addr=, is_req=0, transport=1, switch=0, callBack=0x0<br>Mar 18 08:13:02.168: //7332/60C4BCDF85DE/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately<br>
Mar 18 08:13:02.168: //7332/60C4BCDF85DE/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0<br>Mar 18 08:13:02.168: //7332/60C4BCDF85DE/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x4BA15A08 to default port=5060<br>
Mar 18 08:13:02.168: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:111.11.11.23, rport:5060 with laddr:<br><br>Mar 18 08:13:02.168: //7332/60C4BCDF85DE/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x4BA15A08<br>
Mar 18 08:13:02.168: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x4BA15A08, addr=111.11.11.23, port=5060, local_addr=, connId=2 for UDP<br>Mar 18 08:13:02.168: //7332/60C4BCDF85DE/SIP/State/sipSPIChangeState: 0x4C3019A8 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (STATE_RECD_INVITE, SUBSTATE_NONE)<br>
Mar 18 08:13:02.168: //7332/60C4BCDF85DE/SIP/Info/sipSPIProcessContactInfo: Previous Hop <a href="http://111.11.11.23:5060">111.11.11.23:5060</a><br>Mar 18 08:13:02.168: //7332/60C4BCDF85DE/CCAPI/cc_process_call_setup_ind:<br>
   Event=0x4C09EC88<br>Mar 18 08:13:02.168: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:<br>   Try with the demoted called number 5555555<br>Mar 18 08:13:02.172: //7332/60C4BCDF85DE/CCAPI/ccCallSetContext:<br>   Context=0x48E43778<br>
Mar 18 08:13:02.172: //7332/60C4BCDF85DE/CCAPI/cc_process_call_setup_ind:<br>   >>>>CCAPI handed cid 7332 with tag 44 to app "_ManagedAppProcess_Default"<br>Mar 18 08:13:02.172: //7332/60C4BCDF85DE/CCAPI/ccCallProceeding:<br>
   Progress Indication=NULL(0)<br>Mar 18 08:13:02.172: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDING<br>Mar 18 08:13:02.176: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:<br>
   Try with the demoted called number 5555555<br>Mar 18 08:13:02.176: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:<br><br>Mar 18 08:13:02.176: : updating existing feature vsa<br>Mar 18 08:13:02.176: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:<br>
<br>Mar 18 08:13:02.176:  feature call basic<br>Mar 18 08:13:02.180: //7332/60C4BCDF85DE/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call.<br>Mar 18 08:13:02.180: //7332/60C4BCDF85DE/CCAPI/ccCallDisconnect:<br>
<br>Mar 18 08:13:02.420: //-1/xxxxxxxxxxxx/SIP/Error/sipSPISipIncomingMsg: Invalid method for (STATE_IDLE): ACK<br>Mar 18 08:13:07.724: //-1/xxxxxxxxxxxx/SIP/Info/httpish_msg_process_network_msg: MSG LINE READ FAILURE DUE TO RS->EOF<br>
Mar 18 08:13:07.724: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_network_message: process_network_msg: not complete<br>Mar 18 08:13:07.724: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:<br>Received:<br>...<br>Mar 18 08:13:07.728: //-1/xxxxxxxxxxxx/SIP/Error/HandleUdpIPv4SocketReads: SIP Message incomplete, trashed<br>
Mar 18 08:13:09.980: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x4C3019A8) with key=[7087] to table<br>Mar 18 08:13:09.980: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...<br>Mar 18 08:13:09.980: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:<br>
Mar 18 08:13:09.980: //-1/000000000000/SIP/Info/ccsipRegisterSetTargetInfo: p2p mode with Registrar Server = dns:<a href="http://sipserver.com">sipserver.com</a><br>Mar 18 08:13:09.980: //-1/000000000000/SIP/Info/ccsipRegisterSetTargetInfo: Parsing The Registrar Address<br>
Mar 18 08:13:09.980: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : <a href="http://sipserver.com">sipserver.com</a> target_port : 5060<br><br>Mar 18 08:13:09.980: //-1/000000000000/SIP/Info/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host<br>
Mar 18 08:13:09.980: //-1/000000000000/SIP/Info/sipSPIOutboundProxyReuse: Do not reuse Outbound Proxy IP adress and Port<br>Mar 18 08:13:09.980: //-1/000000000000/SIP/State/sipSPIChangeState: 0x4C3019A8 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)<br>
Mar 18 08:13:09.980: //-1/000000000000/SIP/Info/ccsip_spi_registrar_add_expires_header: Inside ccsip_spi_registrar_add_expires_header for Expires<br>Mar 18 08:13:09.980: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_OUTBOUND_REGISTER<br>
Mar 18 08:13:09.980: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIIncrementOverloadCount: Local 1 Global 1<br>Mar 18 08:13:09.980: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 42<br>
Mar 18 08:13:09.980: //-1/000000000000/SIP/Info/act_idle_outgoing_register: In act_idle_outgoing_register<br><br>Mar 18 08:13:09.984: //7333/000000000000/SIP/Info/act_idle_outgoing_register:  Send REGISTER to <a href="http://sipserver.com:5060">sipserver.com:5060</a><br>
<br>Mar 18 08:13:09.984: //7333/000000000000/SIP/Info/sipSPIUaddCcbToUACTable: ****Adding to UAC table.<br>Mar 18 08:13:09.984: //7333/000000000000/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x4C3019A8 key=F9607D68-4FF811E0-8521847A-CE1311EB<br>
Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_DNS_RESOLVE<br>Mar 18 08:13:09.984: //7333/000000000000/SIP/State/sipSPIChangeState: 0x4C3019A8 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_SENT_DNS)<br>
Mar 18 08:13:09.984: //7333/000000000000/SIP/State/sipSPIChangeState: 0x4C3019A8 : State change from (STATE_IDLE, SUBSTATE_SENT_DNS)  to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_SENT_DNS)<br>Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: TYPE SRV query for _sip._<a href="http://udp.sipserver.com">udp.sipserver.com</a> and type:1<br>
Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Server Name <a href="http://sipserver.com">sipserver.com</a><br>Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Priority 0 Weight 0 Port 5060<br>
Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Selected Server is <a href="http://sipserver.com">sipserver.com</a><br>Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_query: TYPE A query successful for <a href="http://sipserver.com">sipserver.com</a><br>
Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: IP Address of <a href="http://sipserver.com">sipserver.com</a> is:<br><br>Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: 111.11.11.23<br>
<br>Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 45<br>Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICacheHostToCCB: sipSPICacheHostToCCB dnsResponse.num_hosts = 1<br>
Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICacheHostToCCB: IP Address No. 1, IP address 111.11.11.23<br>Mar 18 08:13:09.988: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()<br>
Mar 18 08:13:09.988: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()<br>Mar 18 08:13:09.988: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 22.22.22.17<br>
Mar 18 08:13:09.988: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_spi_register_get_rcb: Getting New RCB [0x4BF13F78]<br>Mar 18 08:13:09.988: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_register_set_dns_resolved_address: CCSIP_REGISTER:: registrar 0 DNS resolved addr set to <a href="http://111.11.11.23:5060">111.11.11.23:5060</a><br>
Mar 18 08:13:09.988: //-1/xxxxxxxxxxxx/SIP/Info/ccsipRegisterStartRCBTimer: Starting timer for pattern  for 3600 seconds<br>Mar 18 08:13:09.988: //7333/000000000000/SIP/State/sipSPIChangeState: 0x4C3019A8 : State change from (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_SENT_DNS)  to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE)<br>
Mar 18 08:13:09.988: //7333/000000000000/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 7 event<br>Mar 18 08:13:09.988: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB<br>
Mar 18 08:13:09.988: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB<br>Mar 18 08:13:09.988: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT<br>
Mar 18 08:13:09.988: //7333/000000000000/SIP/Info/sipSPISendRegister: Associated container=0x4E05D238 to Register<br>Mar 18 08:13:09.988: //7333/000000000000/SIP/Transport/sipSPISendRegister: Sending REGISTER to the transport layer<br>
Mar 18 08:13:09.988: //7333/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE<br>Mar 18 08:13:09.988: //7333/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x48F4CD34, addr=111.11.11.23, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x41BD6D34<br>
Mar 18 08:13:09.992: //7333/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately<br>Mar 18 08:13:09.992: //7333/000000000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0<br>
Mar 18 08:13:09.992: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:111.11.11.23, rport:5060 with laddr:<br><br>Mar 18 08:13:09.992: //7333/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x48F4CD34<br>
Mar 18 08:13:09.992: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x48F4CD34, addr=111.11.11.23, port=5060, local_addr=, connId=2 for UDP<br>Mar 18 08:13:09.992: //7333/000000000000/SIP/State/sipSPIChangeState: 0x4C3019A8 : State change from (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE)  to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE)<br>
<br><br>Thanks,<br>Sam<br>