[cisco-voip] callmanager and did trigger - not working..

sam singapore sam4sg at gmail.com
Fri Mar 18 04:46:21 EDT 2011


Hi,

I am new to this list and facing an error.
I have welcome application set at 004412345678
If I dial that number from any cisco phones, it will play the message.

But when I dial that number (which is our DID) from outside, it does not
play anything and the line is disconnected.
I cannot find out why it is doing so.


Below are the logs for you to check.

I have modified the IPs, but rest all are intact.

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.

Please check and help me to pinpoint the issue.



changed ip addresses:

caller: 0065123456789
DID: 004412345678
sip provider: sipserver.com
our sip username: 555555




dial-peer voice 44 voip
 answer-address 004412345678
 destination-pattern 004412345678
 session protocol sipv2
 session target ipv4:192.168.0.2
 incoming called-number .T
 dtmf-relay rtp-nte
 no vad



cisco#sh debugging


CCAPI:
  debug voip ccapi inout is ON (filter is OFF)
CCSIP SPI: SIP Call Statistics tracing is enabled       (filter is OFF)
CCSIP SPI: SIP Call Message tracing is enabled  (filter is OFF)
CCSIP SPI: SIP Call State Machine tracing is enabled    (filter is OFF)
CCSIP SPI: SIP Call Events tracing is enabled   (filter is OFF)
CCSIP SPI: SIP error debug tracing is enabled   (filter is OFF)
CCSIP SPI: SIP info debug tracing is enabled    (filter is OFF)
CCSIP SPI: SIP media debug tracing is enabled   (filter is OFF)
CCSIP SPI: SIP Call preauth tracing is enabled  (filter is OFF)
CCSIP SPI: SIP Call transport tracing is enabled        (filter is OFF)
CCSIP SPI: SIP DHCP tracing is enabled  (filter is OFF)



cisco#term moni
cisco#
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:[ - ]
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
Mar 18 08:13:02.120:
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg:
context=0x4A602534
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
Mar 18 08:13:02.120: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:5555555 at 22.22.22.17:5060 SIP/2.0
Record-Route: <sip:111.11.11.23;lr=on;ftag=as0c4d53e7>
Record-Route: <sip:172.20.40.1;lr=on>
Record-Route: <sip:111.11.11.23;lr=on;ftag=as0c4d53e7>
Via: SIP/2.0/UDP 111.11.11.23:5060;branch=z9hG4bK7919.8eeefca1.0
Via: SIP/2.0/UDP 172.20.40.1;branch=z9hG4bK7919.8eeefca1.0
Via: SIP/2.0/UDP 111.11.11.23:5060
;received=217.10.68.222;branch=z9hG4bK62007f0f
Via: SIP/2.0/UDP 111.10.11.135:5060;branch=z9hG4bK62007f0f;rport=5060
From: "0065123456789" <sip:0065123456789 at sipserver.com>;tag=as0c4d53e7
To: <sip:004412345678 at sipserver.com>
Contact: <sip:0065123456789 at 111.10.57.135>
Call-ID: 51b0a1d14887a9b00a7a9dd4503a354b at sipserver.com
CSeq: 102 INVITE
Max-Forwards: 67
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Type: application/sdp
Content-Length: 447

v=0
o=root 4047 4047 IN IP4 111.10.11.135
s=session
c=IN IP4 110.10.77.21
t=0 0
m=audio 43670 RTP/AVP 8 0 3 97 18 112 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=30
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:112 G726-32/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
a=direction:active
a=nortpproxy:yes

Mar 18 08:13:02.120: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor:
Checking Invite Dialog
Mar 18 08:13:02.120: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable:
Added context(0x4C3019A8) with key=[7086] to table
Mar 18 08:13:02.120:
//-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...
Mar 18 08:13:02.124: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
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
Mar 18 08:13:02.124:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling
reg_invoke_ip_first_hop()
Mar 18 08:13:02.124:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling
ip_best_local_address()
Mar 18 08:13:02.124:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr
22.22.22.17
Mar 18 08:13:02.124: //-1/60C4BCDF85DE/SIP/State/sipSPIChangeState:
0x4C3019A8 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE,
SUBSTATE_NONE)
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
Mar 18 08:13:02.124: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock
Time Zone is UTC, same as GMT: Using GMT
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
Mar 18 08:13:02.124:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling
reg_invoke_ip_first_hop()
Mar 18 08:13:02.124:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling
ip_best_local_address()
Mar 18 08:13:02.128:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr
22.22.22.17
Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/sipSPICheckAssertedIdConfig:
Dialpeer match is not yet done
Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/sipSPICheckAssertedIdConfig:
Dialpeer match is not yet done
Mar 18 08:13:02.128: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD
found in inbound container
Mar 18 08:13:02.128: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCSTA: No
CSTA found in inbound container
Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/sipSPIUaddCcbToUASReqTable:
****Adding to UAS Request table.
Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/sipSPIUaddCcbToTable: Added
to table. ccb=0x4C3019A8
key=51b0a1d14887a9b00a7a9dd4503a354b at sipserver.com5555555
Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/sipSPIMatchSrcIpGroup: Match
not found on carrier id
Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/sipSPIMatchSrcIpGroup: Match
not found on Incoming called number: 5555555
Mar 18 08:13:02.128: //-1/60C4BCDF85DE/SIP/Info/sipSPIMatchSrcIpGroup: Match
not found on destination pattern: 0065123456789
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
Mar 18 08:13:02.132: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetViaHostInURLFormat:
VIA URL:sip:111.11.11.23:5060, Host:111.11.11.23
Mar 18 08:13:02.132: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetShrlPeer: Try match
incoming dialpeer for Calling number: : 0065123456789
Mar 18 08:13:02.132: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetFromCalledPartyId:
P-Called-Party-ID header not found
Mar 18 08:13:02.132:
//-1/60C4BCDF85DE/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID
not found or parse error
Mar 18 08:13:02.132: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetCallConfig: No
match found for P-Called-Party-ID
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetCallConfig: Peer
tag 44 matched for incoming call
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetCallConfig:
Precondition tag absent in Require/Supported header
Mar 18 08:13:02.136:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling
reg_invoke_ip_first_hop()
Mar 18 08:13:02.136:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling
ip_best_local_address()
Mar 18 08:13:02.136:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr
22.22.22.17
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetCallConfig:
Precondition tag absent in Require/Supported header
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetCallConfig: Media
Antitrombone disabled
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPISetMediaFlowMode:
Storing the configured mode as FLOW-THROUGH
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPISetMediaFlowMode:
xcoder high-density disabled
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPISetMediaFlowMode: Flow
Mode set to FLOW_THROUGH
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetCallConfig:
Checking Video Type Rate=-1 video_codec_allowed=1F
Mar 18 08:13:02.136:
//-1/60C4BCDF85DE/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall
traversal is not enabled
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetModemInfoPerCall:
peer_callID=0
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIGetCallConfig: Media
forking disabled
Mar 18 08:13:02.136:
//-1/60C4BCDF85DE/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling:
FALSE: Endpt: SIP Trunk
Mar 18 08:13:02.136:
//-1/60C4BCDF85DE/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough
config:1 tag:0
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPI_ipip_GetCopyListCfg:
Copy-list config:2 tag:0
Mar 18 08:13:02.136:
//-1/60C4BCDF85DE/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both
passthru and copylist are disabled
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
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
Mar 18 08:13:02.136: //-1/60C4BCDF85DE/SIP/Info/sipSPIValidateRequestUri:
Not Enabled
Mar 18 08:13:02.140: //-1/60C4BCDF85DE/SIP/Info/sipSPIRscmsmAvail: Value
returned by check is = 0
Mar 18 08:13:02.140:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_IsSDPPassthruEnabled:  - 0
Mar 18 08:13:02.140:
//7332/60C4BCDF85DE/SIP/Event/Session-Timer/sipSTSLMain: Event:
E_STSL_SESSION_REFRESH_REQ
Mar 18 08:13:02.140:
//7332/60C4BCDF85DE/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102,
resp_code:0, container:4E05B0E0
Mar 18 08:13:02.140:
//7332/60C4BCDF85DE/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr:
Not received session expires header
Mar 18 08:13:02.140:
//7332/60C4BCDF85DE/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent:
E_STSL_INITIAL_SR_REQ
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
Mar 18 08:13:02.140: //7332/60C4BCDF85DE/SIP/Info/Session-Timer/sipSTSLMain:
        SE: 0;refresher:none peer refresher:none, flags:2000, posted
event:E_STSL_INVALID_PEER_EVENT, reason:4
        Configured SE:1800, Configured Min-SE:1800
Mar 18 08:13:02.140:
//7332/60C4BCDF85DE/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers
recvd from app container
Mar 18 08:13:02.140:
//7332/60C4BCDF85DE/SIP/Info/sipSPIProcessDiversionHeader: No diversion
headers recvd from app container
Mar 18 08:13:02.140:
//7332/60C4BCDF85DE/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr
found
SIP: Warning: No network type specified in comediadir attribute.
SIP: Warning: Unrecognized attribute (nortpproxy)
Mar 18 08:13:02.144: //7332/60C4BCDF85DE/SIP/Info/sipSPIDoMediaNegotiation:
Number of m-lines = 1
Mar 18 08:13:02.144:
//7332/60C4BCDF85DE/SIP/Info/sipSPIValidateConnectionAddress: Dest port =
43670
SIP: (7332) Attribute mid, level 1 instance 1 not found.
Mar 18 08:13:02.144:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling
reg_invoke_ip_first_hop()
Mar 18 08:13:02.144:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling
ip_best_local_address()
Mar 18 08:13:02.144:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr
22.22.22.17
Mar 18 08:13:02.144: //7332/60C4BCDF85DE/SIP/Media/sipSPISetMediaSrcAddr:
Media src addr for stream 1 = 22.22.22.17
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse:
Dynamic payload(97) reserved for codec ilbc
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse:
Dynamic payload(97) could not be reserved
                          as its in use by other codec ilbc
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT:
Requested payload-Type (97) is  reserved by another application
Mar 18 08:13:02.144:
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving
dynamic payload type 116
Mar 18 08:13:02.144:
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving
dynamic payload type 97
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT:
Allocating free Dynamic Payload : 98 for Codec:
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse:
Dynamic payload(112) reserved for codec g726r32
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse:
Dynamic payload(112) reserved for codec g726r32
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse:
Dynamic payload(101) reserved for codec No Codec
Mar 18 08:13:02.144:
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving
dynamic payload type 96
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse:
Dynamic payload(101) could not be reserved
                          as its in use by other codec No Codec
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT:
Requested payload-Type (101) is  reserved by another application
Mar 18 08:13:02.144:
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving
dynamic payload type 99
Mar 18 08:13:02.144:
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving
dynamic payload type 101
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT:
Allocating free Dynamic Payload : 99 for Codec:
Mar 18 08:13:02.144: //-1/xxxxxxxxxxxx/SIP/Info/rtpAvpCodec_to_voipCodec:
Dynamic Payload :97 in SDP Body
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Media/sipSPISelectCodecVersion:
g729r8 flavor of g729 codec will be used
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPIDoAudioNegotiation:
Codec (g729r8) Negotiation Successful on Static Payload for m-line 1
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPIDoPtimeNegotiation:
One ptime attribute found - value:20
Mar 18 08:13:02.148:
//-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec:
g729r8 ptime :20, codecbytes: 20
Mar 18 08:13:02.148:
//-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec:
g729r8 codecbytes :20, ptime: 20
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Media/sipSPIDoPtimeNegotiation:
Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 20 for codec
g729r8
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/sipSPISetFaxFlags:
FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0
Mar 18 08:13:02.148:
//7332/60C4BCDF85DE/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
Mar 18 08:13:02.148: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse:
Dynamic payload(101) reserved for codec
Mar 18 08:13:02.148: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse:
Dynamic payload(101) reserved for codec
Mar 18 08:13:02.148:
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving
dynamic payload type 99
Mar 18 08:13:02.148:
//7332/60C4BCDF85DE/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the
payload type 101 for RTP-NTE
Mar 18 08:13:02.148:
//7332/60C4BCDF85DE/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF
relay option
Mar 18 08:13:02.148:
//7332/60C4BCDF85DE/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of full
named event(NE) match in fmtp list of events.
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
Mar 18 08:13:02.148:
//7332/60C4BCDF85DE/SIP/Info/sip_select_modem_relay_params: X-tmr not
present in SDP. Disable modem relay
Mar 18 08:13:02.148:
//7332/60C4BCDF85DE/SIP/Info/sipSPIGetSDPDirectionAttribute: Extraction of
src address triggered with media direction role as: 1
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/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=111.10.77.21,
dest_port=43670
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/State/sipSPIChangeStreamState:
Stream (callid =  -1)  State changed from (STREAM_DEAD) to (STREAM_ADDING)
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Media/sipSPIUpdCallWithSdpInfo:
        Preferred Codec        : g729r8, bytes :20
        Preferred  DTMF relay  : rtp-nte
        Preferred NTE payload  : 101
        Early Media            : No
        Delayed Media          : No
        Bridge Done            : No
        New Media              : No
        DSP DNLD Reqd          : No

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
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Media/sipSPISetMediaSrcAddr:
Media src addr for stream 1 = 22.22.22.17
Mar 18 08:13:02.148:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_report_media_to_peer:
 callId 7332 peer 0 flags 0x201 state STATE_IDLE
Mar 18 08:13:02.148:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_vcc_ProcessXcoderNeeded:
xcoder_attached not yet initialised for this call.
Mar 18 08:13:02.148:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_report_media_to_peer: Xcoder not
yet used for the call
Mar 18 08:13:02.148:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 7332, Peer CallID 0, sdp 0x4C1DA6B4 channels 0x4C302F44
Mar 18 08:13:02.148: //7332/60C4BCDF85DE/SIP/Info/copy_channels:
 callId 7332 size 0 ptr 0x4ACF7EDC)
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: reset the
switch..
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 8 mline 1
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting
codec g711alaw
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found:
Codec to be matched: 6
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found: No match for
the codecs found..
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 0 mline 1
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting
codec g711ulaw
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found:
Codec to be matched: 5
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found: No match for
the codecs found..
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 3 mline 1
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting
codec gsmfr
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found:
Codec to be matched: 10
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found: No match for
the codecs found..
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 97 mline 1
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found:
Codec to be matched: 33
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found: No match for
the codecs found..
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 18 mline 1
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Media/sipSPISelectCodecVersion:
g729r8 flavor of g729 codec will be used
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting
codec g729r8
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found:
Codec to be matched: 16
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found:  codecs[i] =
16 & codec = 16 are same..
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO
CODEC 16

Mar 18 08:13:02.152:
//-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec:
g729r8 codecbytes :20, ptime: 20
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
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
failed to update call entry
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 16 ptype 18 time 20, bytes 20  as channel 0 mline 1 ss 0
111.10.77.21:43670
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 112 mline 1
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found:
Codec to be matched: 4
Mar 18 08:13:02.152: //7332/60C4BCDF85DE/SIP/Info/codec_found: No match for
the codecs found..
Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 101 mline 1
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
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

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

Mar 18 08:13:02.152:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_report_media_to_peer:
 callId 7332 flags 0x10000100 state STATE_IDLE
Mar 18 08:13:02.156:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_report_media_to_peer:
Report initial call media
Mar 18 08:13:02.156:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags
0xC, ccb->pld.flags_ipip 0x201

Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/copy_channels:
 callId 7332 size 240 ptr 0x4E3C5E8C)
Mar 18 08:13:02.156:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_report_media_to_peer:
CCSIP: Unable to report channel ind
Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/ccsip_update_srtp_caps:
7421: Posting Remote SRTP caps to other callleg.
Mar 18 08:13:02.156:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_report_media_to_peer: do
cc_api_caps_ind()
Mar 18 08:13:02.156: //7332/xxxxxxxxxxxx/CCAPI/cc_api_caps_ind:
   Call Entry Is Not Found
Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Media/sipSPIUpdCallWithSdpInfo:
          Stream type            : voice+dtmf
          Media line             : 1
          State                  : STREAM_ADDING (2)
          Stream address type    : 1
          Callid                 : -1
          Negotiated Codec       : g729r8, bytes :20
          Nego. Codec payload    : 18 (tx), 18 (rx)
          Negotiated DTMF relay  : rtp-nte
          Negotiated NTE payload : 101 (tx), 101 (rx)
          Negotiated CN payload  : 0
          Media Srce Addr/Port   : [22.22.22.17]:0
          Media Dest Addr/Port   : [111.10.77.21]:43670

Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPIHandleInviteMedia:
Negotiated Codec       : g729r8, bytes :20
Preferred Codec        : g729r8, bytes :20
Preferred  DTMF relay 1 : 6
Preferred  DTMF relay 2 : 0
Negotiated DTMF relay   : 6
Preferred and Negotiated NTE payloads: 101 101
Preferred and Negotiated NSE payloads: 100 0
Preferred and Negotiated Modem Relay: 0 0
Preferred and Negotiated V150.1 Modem Passthrough: 0 0
Preferred and Negotiated V150.1 Modem Relay: 0 0
Preferred and Negotiated Modem Relay GwXid: 1 0

Mar 18 08:13:02.156:
//7332/60C4BCDF85DE/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS
negotiation for mline_index 1
Mar 18 08:13:02.156:
//7332/60C4BCDF85DE/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort
Mar 18 08:13:02.156: //7332/60C4BCDF85DE/SIP/Info/sipSPICanSetFallbackFlag:
Local Fallback is not active
Mar 18 08:13:02.156: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort:
reserved port 18470 for stream 1
Mar 18 08:13:02.156:
//7332/60C4BCDF85DE/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port
for stream 1, src_port=18470
Mar 18 08:13:02.156:
//-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media
direction SENDRECV for stream 1
Mar 18 08:13:02.156:
//7332/60C4BCDF85DE/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream
1 portnum to 18470
Mar 18 08:13:02.156:
//7332/60C4BCDF85DE/SIP/Info/sipSPIUpdateSrcSdpVariablePart:
 SIP update src sdp, negoitated codec 16, payload type 18

Mar 18 08:13:02.156:
//7332/60C4BCDF85DE/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Negotiated
method of dtmf relayand pyld: 6 101

Mar 18 08:13:02.156:
//7332/60C4BCDF85DE/SIP/Info/sipSPIUpdateSrcSdpVariablePart: max_event 16
Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPIAddBillingInfoToCcb:
sipCallId for billing records =
51b0a1d14887a9b00a7a9dd4503a354b at sipserver.com
Mar 18 08:13:02.160: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA
found in inbound container
Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPIProcessCPA: No
x-cisco-cpa content found
Mar 18 08:13:02.160:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough
config:1 tag:0
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
Mar 18 08:13:02.160:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled:  - 0
Mar 18 08:13:02.160:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer:
Passthru Content Not Enabled
Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Error/ccsip_api_call_setup_ind:
Unable to add unsupp headers to container
Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/ccsip_api_call_setup_ind:
Set Protocol information
Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_antiTrombone:
Entered Antitrombone service
Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_antiTrombone:
Antitrombone service not configured
Mar 18 08:13:02.160:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_store_channel_info: Store
channelInfo in CallInfo
Mar 18 08:13:02.160:
//7332/60C4BCDF85DE/SIP/Info/sipSPI_ipip_store_channel_info: dtmf
negotiation done, storing negotiated dtmf = 6,
Mar 18 08:13:02.160: //7332/60C4BCDF85DE/SIP/Info/sipSPIShrlCall: Check
peer: 44 for Shared-Line call, callid: 7332
Mar 18 08:13:02.160:
//7332/60C4BCDF85DE/SIP/Info/ccsip_set_bearer_capability:
   Bearer Capability: Speech (0x00)
Mar 18 08:13:02.160: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No
QSIG Body found in inbound container
Mar 18 08:13:02.160: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No
RawMsg Body found in inbound container
Mar 18 08:13:02.160: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No
Data to form The Raw Message

Mar 18 08:13:02.160: //-1/60C4BCDF85DE/CCAPI/cc_api_display_ie_subfields:
   cc_api_call_setup_ind_common:
   cisco-username=0065123456789
   ----- ccCallInfo IE subfields -----
   cisco-ani=0065123456789
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=5555555
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFF
   cisco-rdn=
   cisco-rdntype=0
   cisco-rdnplan=0
   cisco-rdnpi=-1
   cisco-rdnsi=-1
   cisco-redirectreason=-1   fwd_final_type =0
   final_redirectNumber =
   hunt_group_timeout =0

Mar 18 08:13:02.164: //-1/60C4BCDF85DE/CCAPI/cc_api_call_setup_ind_common:
   Interface=0x4A6056C0, Call Info(
   Calling Number=0065123456789,(Calling Name=)(TON=Unknown, NPI=Unknown,
Screening=Not Screened, Presentation=Allowed),
   Called Number=5555555(TON=Unknown, NPI=Unknown),
   Calling Translated=FALSE, Subscriber Type Str=Unknown,
FinalDestinationFlag=TRUE,
   Incoming Dial-peer=44, Progress Indication=NULL(0), Calling IE
Present=TRUE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID
Transparent=FALSE), Call Id=7332
Mar 18 08:13:02.164: //-1/60C4BCDF85DE/CCAPI/ccCheckClipClir:
   In: Calling Number=0065123456789(TON=Unknown, NPI=Unknown, Screening=Not
Screened, Presentation=Allowed)
Mar 18 08:13:02.164: //-1/60C4BCDF85DE/CCAPI/ccCheckClipClir:
   Out: Calling Number=0065123456789(TON=Unknown, NPI=Unknown, Screening=Not
Screened, Presentation=Allowed)
Mar 18 08:13:02.164: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 18 08:13:02.164: :cc_get_feature_vsa malloc success
Mar 18 08:13:02.164: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 18 08:13:02.164:  cc_get_feature_vsa count is 1
Mar 18 08:13:02.164: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Mar 18 08:13:02.164: :FEATURE_VSA attributes are:
feature_name:0,feature_time:1222875552,feature_id:473
Mar 18 08:13:02.164: //7332/60C4BCDF85DE/CCAPI/cc_api_call_setup_ind_common:
   Set Up Event Sent;
   Call Info(Calling Number=0065123456789(TON=Unknown, NPI=Unknown,
Screening=Not Screened, Presentation=Allowed),
   Called Number=5555555(TON=Unknown, NPI=Unknown))
Mar 18 08:13:02.164:
//7332/60C4BCDF85DE/SIP/Info/sipSPIContinueNewMsgInvite:
ccsip_api_call_setup_ind returned: SIP_SUCCESS
Mar 18 08:13:02.164: //7332/60C4BCDF85DE/SIP/Info/sipSPIUaddccCallIdToTable:
Adding call id 1CA4 to table
Mar 18 08:13:02.164:
//7332/60C4BCDF85DE/SIP/Event/Session-Timer/sipSTSLMain: Event:
E_STSL_SESSION_REFRESH_RESP
Mar 18 08:13:02.164:
//7332/60C4BCDF85DE/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102,
resp_code:100, container:4E05B500
Mar 18 08:13:02.164:
//7332/60C4BCDF85DE/SIP/Info/Session-Timer/sipSTSLValidateSessRefreshMsg:
Ignoring 1xx response for session timer processing
Mar 18 08:13:02.168: //7332/60C4BCDF85DE/SIP/Info/sipSPISendInviteResponse:
Associated container=0x4E05B500 to Invite Response 100
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
Mar 18 08:13:02.168:
//7332/60C4BCDF85DE/SIP/Transport/sipSPITransportSendMessage: Proceedable
for sending msg immediately
Mar 18 08:13:02.168:
//7332/60C4BCDF85DE/SIP/Transport/sipTransportLogicSendMsg: switch transport
is 0
Mar 18 08:13:02.168:
//7332/60C4BCDF85DE/SIP/Transport/sipTransportLogicSendMsg: Trying to send
resp=0x4BA15A08 to default port=5060
Mar 18 08:13:02.168:
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection:
connection required for raddr:111.11.11.23, rport:5060 with laddr:

Mar 18 08:13:02.168:
//7332/60C4BCDF85DE/SIP/Transport/sipTransportLogicSendMsg: Connection
obtained...sending msg=0x4BA15A08
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
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)
Mar 18 08:13:02.168: //7332/60C4BCDF85DE/SIP/Info/sipSPIProcessContactInfo:
Previous Hop 111.11.11.23:5060
Mar 18 08:13:02.168: //7332/60C4BCDF85DE/CCAPI/cc_process_call_setup_ind:
   Event=0x4C09EC88
Mar 18 08:13:02.168: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
   Try with the demoted called number 5555555
Mar 18 08:13:02.172: //7332/60C4BCDF85DE/CCAPI/ccCallSetContext:
   Context=0x48E43778
Mar 18 08:13:02.172: //7332/60C4BCDF85DE/CCAPI/cc_process_call_setup_ind:
   >>>>CCAPI handed cid 7332 with tag 44 to app "_ManagedAppProcess_Default"
Mar 18 08:13:02.172: //7332/60C4BCDF85DE/CCAPI/ccCallProceeding:
   Progress Indication=NULL(0)
Mar 18 08:13:02.172: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued
event from SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDING
Mar 18 08:13:02.176: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
   Try with the demoted called number 5555555
Mar 18 08:13:02.176: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

Mar 18 08:13:02.176: : updating existing feature vsa
Mar 18 08:13:02.176: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:

Mar 18 08:13:02.176:  feature call basic
Mar 18 08:13:02.180: //7332/60C4BCDF85DE/SIP/Info/ccsip_call_statistics:
Stats are not supported for IPIP call.
Mar 18 08:13:02.180: //7332/60C4BCDF85DE/CCAPI/ccCallDisconnect:

Mar 18 08:13:02.420: //-1/xxxxxxxxxxxx/SIP/Error/sipSPISipIncomingMsg:
Invalid method for (STATE_IDLE): ACK
Mar 18 08:13:07.724:
//-1/xxxxxxxxxxxx/SIP/Info/httpish_msg_process_network_msg: MSG LINE READ
FAILURE DUE TO RS->EOF
Mar 18 08:13:07.724:
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_network_message:
process_network_msg: not complete
Mar 18 08:13:07.724: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
...
Mar 18 08:13:07.728: //-1/xxxxxxxxxxxx/SIP/Error/HandleUdpIPv4SocketReads:
SIP Message incomplete, trashed
Mar 18 08:13:09.980: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable:
Added context(0x4C3019A8) with key=[7087] to table
Mar 18 08:13:09.980:
//-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...
Mar 18 08:13:09.980: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
Mar 18 08:13:09.980: //-1/000000000000/SIP/Info/ccsipRegisterSetTargetInfo:
p2p mode with Registrar Server = dns:sipserver.com
Mar 18 08:13:09.980: //-1/000000000000/SIP/Info/ccsipRegisterSetTargetInfo:
Parsing The Registrar Address
Mar 18 08:13:09.980:
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP:
target_host : sipserver.com target_port : 5060

Mar 18 08:13:09.980:
//-1/000000000000/SIP/Info/sipSPIValidateAndCopyOutboundHost: CCSIP: copy
target_host to outbound_host
Mar 18 08:13:09.980: //-1/000000000000/SIP/Info/sipSPIOutboundProxyReuse: Do
not reuse Outbound Proxy IP adress and Port
Mar 18 08:13:09.980: //-1/000000000000/SIP/State/sipSPIChangeState:
0x4C3019A8 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE,
SUBSTATE_NONE)
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
Mar 18 08:13:09.980: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued
event from SIP SPI : SIPSPI_EV_OUTBOUND_REGISTER
Mar 18 08:13:09.980:
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIIncrementOverloadCount: Local 1 Global 1
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
Mar 18 08:13:09.980: //-1/000000000000/SIP/Info/act_idle_outgoing_register:
In act_idle_outgoing_register

Mar 18 08:13:09.984:
//7333/000000000000/SIP/Info/act_idle_outgoing_register:  Send REGISTER to
sipserver.com:5060

Mar 18 08:13:09.984: //7333/000000000000/SIP/Info/sipSPIUaddCcbToUACTable:
****Adding to UAC table.
Mar 18 08:13:09.984: //7333/000000000000/SIP/Info/sipSPIUaddCcbToTable:
Added to table. ccb=0x4C3019A8 key=F9607D68-4FF811E0-8521847A-CE1311EB
Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued
event from SIP SPI : SIPSPI_EV_DNS_RESOLVE
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)
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)
Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: TYPE
SRV query for _sip._udp.sipserver.com and type:1
Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query:
Server Name sipserver.com
Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query:
Priority 0 Weight 0 Port 5060
Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query:
Selected Server is sipserver.com
Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_query: TYPE A
query successful for sipserver.com
Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: IP
Address of sipserver.com is:

Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query:
111.11.11.23

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
Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICacheHostToCCB:
sipSPICacheHostToCCB dnsResponse.num_hosts = 1
Mar 18 08:13:09.984: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICacheHostToCCB: IP
Address No. 1, IP address 111.11.11.23
Mar 18 08:13:09.988:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling
reg_invoke_ip_first_hop()
Mar 18 08:13:09.988:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling
ip_best_local_address()
Mar 18 08:13:09.988:
//-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr
22.22.22.17
Mar 18 08:13:09.988: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_spi_register_get_rcb:
Getting New RCB [0x4BF13F78]
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 111.11.11.23:5060
Mar 18 08:13:09.988: //-1/xxxxxxxxxxxx/SIP/Info/ccsipRegisterStartRCBTimer:
Starting timer for pattern  for 3600 seconds
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)
Mar 18 08:13:09.988: //7333/000000000000/SIP/Info/sipSPIPresendProcessing:
Presend Processing called for 7 event
Mar 18 08:13:09.988:
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIRetrieveOutgoingPassThruData: Retrieving
Data from RCB
Mar 18 08:13:09.988:
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIRetrieveOutgoingPassThruData: Retrieving
Data from RCB
Mar 18 08:13:09.988: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock
Time Zone is UTC, same as GMT: Using GMT
Mar 18 08:13:09.988: //7333/000000000000/SIP/Info/sipSPISendRegister:
Associated container=0x4E05D238 to Register
Mar 18 08:13:09.988: //7333/000000000000/SIP/Transport/sipSPISendRegister:
Sending REGISTER to the transport layer
Mar 18 08:13:09.988:
//7333/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the
Global configuration, Switch Transport is FALSE
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
Mar 18 08:13:09.992:
//7333/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable
for sending msg immediately
Mar 18 08:13:09.992:
//7333/000000000000/SIP/Transport/sipTransportLogicSendMsg: switch transport
is 0
Mar 18 08:13:09.992:
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection:
connection required for raddr:111.11.11.23, rport:5060 with laddr:

Mar 18 08:13:09.992:
//7333/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the
msg=0x48F4CD34
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
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)


Thanks,
Sam
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20110318/02703c3d/attachment.html>


More information about the cisco-voip mailing list