=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2015.02.09 16:05:30 =~=~=~=~=~=~=~=~=~=~=~=
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIgetRegistrarHost: registrar is not configured
//90/4B342D000000/SIP/Event/sipSPICreateRpid: Received Octet3A=0x81 -> Setting ;screen=yes ;privacy=off
//90/4B342D000000/SIP/Info/sipSPISendInvite: Associated container=0x2A4F7674 to Invite
//90/4B342D000000/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
//90/4B342D000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE
//90/4B342D000000/SIP/Transport/sipSPITransportSendMessage: msg=0x314763B0, addr=10.1.45.20, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x24E20C4C
//90/4B342D000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//90/4B342D000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.1.45.20, rport:5060 with laddr:
//90/4B342D000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x314763B0
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x314763B0, addr=10.1.45.20, port=5060, local_addr=, connId=2 for UDP
//90/4B342D000000/SIP/Info/sentInviteRequest: Sent Invite in state STATE_IDLE
//-1/xxxxxxxxxxxx/SIP/Info/sentInviteRequest: Transaction active. Facilities will be queued.
//90/4B342D000000/SIP/State/sipSPIChangeState: 0x40953AB0 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_SENT_INVITE, SUBSTATE_NONE)
//-1/xxxxxxxxxxxx/SIP/Error/HandleUdpSocketWrites: Send failed errno 261
Feb 9 07:49:17.102: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
Feb 9 07:49:17.102: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
Feb 9 07:49:17.102: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x4055DCD4, addr=192.168.50.10, port=41263, local_addr=, connid=2, transport=TCP
Feb 9 07:49:17.102: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
//87/41AAC5000000/SIP/State/sipSPIChangeState: 0x4095E900 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)INVITE sip:08228777303055942@192.168.50.1:5060 SIP/2.0
Via: SIP/2.0/TCP 192.168.50.10:5060;branch=z9hG4bK3d286eb43f
From: "DEMO" <sip:200@192.168.50.10>;tag=63~7f88b1b9-f68d-4857-b8e0-e411cd112197-23099691
To: <sip:08228777303055942@192.168.50.1>
Date: Mon, 09 Feb 2015 07:57:15 GMT
Call-ID: 41aac500-4d81685b-3e-a32a8c0@192.168.50.10
Supported: timer,resource-priority,replaces
Min-SE: 1800
User-Agent: Cisco-CUCM9.1
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOT
//-1/xxxxxxxxxxxx/SIP/Info/udpsock_close_connect: Socket fd: 1 closed for connid 2 with remote port: 5060IFY
CSeq: 101 INVITE
Expires: 180
Allow-Events: presence, kpml
Supported: X-cisco-srtp-fallback,X-cisco-original-called
Call-Info: <sip:192.168.50.10:5060>;method="NOTIFY;Event=telephone-event;Duration=500"
Cisco-Guid: 1101710592-0000065536-0000000062-0171092160
Session-Expires: 1800
P-Asserted-Identity: "DEMO" <sip:200@192.168.50.10>
Remote-Party-ID: "DEMO" <sip:200@192.168.50.10>;party=calling;screen=yes;privacy=off
Contact: <sip:200@192.168.50.10:5060;transport=tcp>;video;audio
Max-Forwards: 70
Content-Length: 0
Feb 9 07:49:17.102: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//89/4B342D000000/CCAPI/ccCallReleaseResources:
Feb 9 07:49:17.102: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x4095E900) with key=[87] to table
Feb 9 07:49:17.102: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization: Entry...
Feb 9 07:49:17.102: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.50.10,Port 41263, Transport 2, SentBy Port 5060
Feb 9 07:49:17.102: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
Feb 9 07:49:17.102: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()release reserved xcoding resource.
Feb 9 07:49:17.102: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 192.168.50.1
Feb 9 07:49:17.102: //-1/41AAC5000000/SIP/State/sipSPIChangeState: 0x4095E900 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
Feb 9 07:49:17.102: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.50.10,Port 41263, Transport 2, SentBy Port 5060
Feb 9 07:49:17.102: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
Feb 9 07:49:17.102: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.50.10,Port 41263, Transport 2, SentBy Port 5060
Feb 9 07:49:17.106: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
Feb 9 07:49:17.106: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
Feb 9 07:49:17.106: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 192.168.50.1
Feb 9 07:49:17.106: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckIpip: VOIP dialpeer (peer=0x2920A79C) found for sip_user: 08228777303055942
%SYS-3-CPUHOG: Task is running for (2168)msecs, more than (2000)msecs (0/0),process = AFW_application_process.
-Traceback= 0x21144C68z 0x2114688Cz 0x21146830z 0x2237BBB0z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24B11F34z 0x24B12934z 0x24A8BBF4z 0x25050B84z 0x25055760z 0x250559B0z 0x2508A71Cz 0x25051120z 0x25059968z
//90/4B342D000000/CCAPI/ccCallSetAAA_Accounting:
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIUpdateIdentity: SIP->PSTN: Setting Calling Name to DEMO
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIUpdateIdentity: SIP->PSTN: Setting Calling Number to 200
Feb 9 07:49:17.106: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
Feb 9 07:49:17.106: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCSTA: No CSTA found in inbound container
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.Accounting=0, Call Id=90
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x4095E900 key=41aac500-4d81685b-3e-a32a8c0@192.168.50.1008228777303055942
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 08228777303055942
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 200
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name DEMO, number 200, Calling oct3 0x00, oct_3a 0x81, Called number 08228777303055942
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:192.168.50.10:5060, Host:192.168.50.10
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 200
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error
%SYS-3-CPUHOG: Task is running for (4564)msecs, more than (2000)msecs (0/0),process = AFW_application_process.
-Traceback= 0x21144C68z 0x2114688Cz 0x2237BBB0z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24C9F710z 0x24A86190z 0x25027CACz 0x25027FB4z 0x25050BBCz 0x25055760z 0x250559B0z 0x2508A71Cz 0x25051120z 0x25059968z
//90/4B342D000000/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call.
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIGetCallConfig: Peer tag 300 matched for incoming call
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
Feb 9 07:49:17.106: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
Feb 9 07:49:17.106: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
Feb 9 07:49:17.106: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 192.168.50.1
%SYS-3-CPUHOG: Task is running for (6572)msecs, more than (2000)msecs (0/0),process = AFW_application_process.
-Traceback= 0x21144C68z 0x2114688Cz 0x2237BBB0z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24B11F34z 0x24B1271Cz 0x24A861E0z 0x25027CACz 0x25027FB4z 0x25050BBCz 0x25055760z 0x250559B0z 0x2508A71Cz 0x25051120z //90/4B342D000000/CCAPI/ccCallDisconnect:
Cause Value=38, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=38)
//90/4B342D000000/CCAPI/ccCallDisconnect:
Cause Value=38, Call Entry(Responsed=TRUE, Cause Value=38)
//-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
//87/41AAC5000000/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/TCP 192.168.50.10:5060;branch=z9hG4bK3d286eb43f
From: "DEMO" <sip:200@192.168.50.10>;tag=63~7f88b1b9-f68d-4857-b8e0-e411cd112197-23099691
To: <sip:08228777303055942@192.168.50.1>
Date: Mon, 09 Feb 2015 07:49:18 GMT
Call-ID: 41aac500-4d81685b-3e-a32a8c0@192.168.50.10
CSeq: 101 CANCEL
Content-Length: 0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8
//90/4B342D000000/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SPI_EVENT
//90/4B342D000000/SIP/Info/Session-Timer/sipSTSLMain:
SE: 1800;refresher:none peer refresher:none, flags:2120, posted event:E_STSL_PASS_ST_PARAMS, reason:4
Configured SE:1800, Configured Min-SE:1800
//90/4B342D000000/SIP/Info/sipSPIIcpifUpdate: CallState: 2 Playout: 0 DiscTime:1638538 ConnTime 0
//90/4B342D000000/CCAPI/cc_api_call_disconnect_done:
Disposition=-11, Interface=0x4055E3B0, Tag=0x0, Call Id=90,
Call Entry(Disconnect Cause=38, Voice Class Cause Code=0, Retry Count=0)
//90/4B342D000000/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
//-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
:cc_free_feature_vsa freeing 30024C68
//-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
vsacount in free is 3
//90/4B342D000000/SIP/State/sipSPIChangeState: 0x40953AB0 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE)
//90/4B342D000000/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x40953AB0
State of The Call : STATE_DEAD
TCP Sockets Used : NO
Calling Number : 200
Called Number : 08228777303055942
Source IP Address (Sig ): 10.1.45.3
Destn SIP Req Addr:Port : 10.1.45.20:5060
Destn SIP Resp Addr:Port : 10.1.45.20:5060
Destination Name : 10.1.45.20
//90/4B342D000000/SIP/Call/sipSPICallInfo:
Disconnect Cause (CC) : 38
Disconnect Cause (SIP) : 200
//90/4B342D000000/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 5A
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteCon
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x21144C2Cz 0x2114688Cz 0x2237B9F4z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24C7E33Cz 0x24C7FF24z 0x24C56D2Cz 0x24C57DA0z 0x24DA246Cz 0x24DA2910z 0x23588E0Cz 0x23588DF0z textFromTable: Context for key=[90] removed.
//90/4B342D000000/SIP/Info/sipSPIUdeleteCcbFromUACTable: ****Deleting from UAC table.
//90/4B342D000000/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x40953AB0 key=FBA3F3EE-AF6611E4-8117B06D-73276674@10.1.45.3
//90/4B342D000000/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
//90/4B342D000000/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
//90/4B342D000000/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 40953AB0
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[90]
//88/41AAC5000000/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call.
//88/41AAC5000000/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
//88/41AAC5000000/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=FALSE, Cause Value=16)
//-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECTterminal monitor
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8
//88/41AAC5000000/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SPI_EVENT
//88/41AAC5000000/SIP/Info/Session-Timer/sipSTSLMain:
SE: 1800;refresher:none peer refresher:none, flags:2120, posted event:E_STSL_PASS_ST_PARAMS, reason:4
Configured SE:1800, Configured Min-SE:1800
//88/41AAC5000000/SIP/Info/act_sentinvite_disconnect: Received POTS Disconnect - Holding CANCEL till we receive a response from remote end.
//87/41AAC5000000/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call.
//87/41AAC5000000/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=16)
//87/41AAC5000000/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
//-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x4055DCD4, addr=192.168.50.10, port=41263, local_addr=, connid=2, transport=TCP
//-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
CANCEL sip:08228777303055942@192.168.50.1:5060 SIP/2.0
Via: SIP/2.0/TCP 192.168.50.10:5060;branch=z9hG4bK3e9db6a06
From: "DEMO" <sip:200@192.168.50.10>;tag=64~7f88b1b9-f68d-4857-b8e0-e411cd112197-23099693
To: <sip:08228777303055942@192.168.50.1>
Date: Mon, 09 Feb 2015 07:57:31 GMT
Call-ID: 4b342d00-4d81686b-3f-a32a8c0@192.168.50.10
CSeq: 101 CANCEL
Max-Forwards: 70
Content-Length: 0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//89/4B342D000000/SIP/Info/sipSPIFindCcbUASReqTable: *****CCB found in UAS Request table. ccb=0x4094E388
//-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.50.10,Port 41263, Transport 2, SentBy Port 5060
//-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
//-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.50.10,Port 41263, Transport 2, SentBy Port 5060
//89/4B342D000000/SIP/Info/ccsip_set_release_source_for_peer: ownCallId[89], src[2]
//-1/xxxxxxxxxxxx/SIP/Error/ccsip_set_release_source_for_peer: Failed AV set
//89/4B342D000000/SIP/State/sipSPIChangeState: 0x4094E388 : State change from (STATE_RECD_INVITE, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)
//89/4B342D000000/SIP/Transport/sipSPISendCance
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (0/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x21144C68z 0x2114688Cz 0x2237B9F4z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24C279C0z 0x24C44710z 0x24C55D6Cz lResponse: Sending CANCEL Response to the transport layer
//89/4B342D000000/SIP/Transport/sipSPITransportSendMessage: msg=0x40A8B45C, addr=192.168.50.10, port=41263, sentBy_port=5060, local_addr=, is_req=0, transport=2, switch=0, callBack=0x0
//89/4B342D000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//89/4B342D000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x40A8B45C, addr=192.168.50.10, port=41263, local_addr=, connId=2 for TCP
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
//89/4B342D000000/SIP/Info/sipSPIInitiateDisconnect: Initiate call disconnect(16) for incoming call
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
//89/4B342D000000/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
//89/4B342D000000/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled: - 0
//89/4B342D000000/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Not Enabled
//89/4B342D000000/CCAPI/cc_api_call_disconnected:
Cause Value=16, Interface=0x4055E3B0, Call Id=89
//89/4B342D000000/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=FALSE, Cause Value=16, Retry Count=0)
//89/4B342D000000/SIP/State/sipSPIChangeState: 0x4094E388 : State change from (STAT
%SYS-3-CPUHOG: Task is running for (4004)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x21144C68z 0x2114688Cz 0x2237B9F4z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24C83974z 0x24BF9754z 0x24C4474Cz 0x24C55D6Cz E_DISCONNECTING, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)
//89/4B342D000000/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call.
//89/4B342D000000/CCAPI/ccCallDisconnect:
Cause Value=38, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=16)
//89/4B342D000000/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
//-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
//89/4B342D000000/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/TCP 192.168.50.10:5060;branch=z9hG4bK3e9db6a06
From: "DEMO" <sip:200@192.168.50.10>;tag=64~7f88b1b9-f68d-4857-b8e0-e411cd112197-23099693
To: <sip:08228777303055942@192.168.50.1>
Date: Mon, 09 Feb 2015 07:49:34 GMT
Call-ID: 4b342d00-4d81686b-3f-a32a8c0@192.168.50.10
CSeq: 101 CANCEL
Content-Length: 0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8
//87/41AAC5000000/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table.
//87/41AAC5000000/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x4095E900 key=41aac500-4d81685b-3e-a32a8c0@192.168.50.10FA2B40-110D
//87/41AAC5000000/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP
//87/41AAC5000000/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:487, container:2A4F75C4
//87/41AAC5000000/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_RESP
//87/41AAC5000000/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_INVALID_PEER_EVENT, SE Value:0, SE Refresher:none, Min-SE Value:0, flags:2120
//87/41AAC5000000/SIP/Info/Session-Timer/sipSTSLMain:
SE: 1800;refresher:none peer refresher:none, flags:1, posted event:E_STSL_INVALID_PEER_EVENT, reason:4
Configured SE:1800, Configured Min-SE:1800
//87/41AAC5000000/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 3 event
//87/41AAC5000000/SIP/Info/sipSPI_ipip_GetPassthruDataFromTdContainer: Could not get any elements from TD Container
//87/41AAC5000000/SIP/Info/sipSPI_ipip_GetPassthruDataFromTdContainer: Could not get any elements from TD Container
//87/41AAC5000000/SIP/Info/sipSPISendInviteResponse: Associated container=0x2A4F75C4 to Invite Response 487
//87/41AAC5000000/SIP/Transport/sipSPITransportSendMessage: msg=0x3002DB00, addr=192.168.50.10, port=41263, sentBy_port=5060, local_addr=, is_req=0, transport=2, switch=0, callBack=0x24E21898
//87/41AAC5000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//87/41AAC5000
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (0/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x21144C68z 0x2114688Cz 0x2237B9F4z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24E1D99Cz 0x24E1F14Cz 0x24C2D350z 0x24C438B4z 0x24C56D2Cz 0x24C57DA0z 0x24DA246Cz 0x24DA2910z 0x23588E0Cz 0x23588DF0z 000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x3002DB00, addr=192.168.50.10, port=41263, local_addr=, connId=2 for TCP
//87/41AAC5000000/SIP/Info/sentRequestCancelDisconnecting: Sent a 487 Request Cancelled
//87/41AAC5000000/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 487 Request Cancelled
Via: SIP/2.0/TCP 192.168.50.10:5060;branch=z9hG4bK3d286eb43f
From: "DEMO" <sip:200@192.168.50.10>;tag=63~7f88b1b9-f68d-4857-b8e0-e411cd112197-23099691
To: <sip:08228777303055942@192.168.50.1>;tag=FA2B40-110D
Date: Mon, 09 Feb 2015 07:49:18 GMT
Call-ID: 41aac500-4d81685b-3e-a32a8c0@192.168.50.10
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Reason: Q.850;cause=16
Content-Length: 0
deb ccsip messages
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8
//89/4B342D000000/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table.
//89/4B342D000000/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x4094E388 key=4b342d00-4d81686b-3f-a32a8c0@192.168.50.10FA3860-0
//89/4B342D000000/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP
//89/4B342D000000/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:487, container:2A4F87A4
//89/4B342D000000/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_RESP
//89/4B342D000000/SIP/Info/Session-Timer/sipSTSLMain:
SE: 1800;refresher:none peer refresher:none, flags:81, posted event:E_STSL_INVALID_PEER_EVENT, reason:3
Configured SE:1800, Configured Min-SE:1800
//89/4B342D000000/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 3 event
//89/4B342D000000/SIP/Info/sipSPI_ipip_GetPassthruDataFromTdContainer: Could not get any elements from TD Container
//89/4B342D000000/SIP/Info/sipSPI_ipip_GetPassthruDataFromTdContainer: Could not get any elements from TD Container
//89/4B342D000000/SIP/Info/sipSPISendInviteResponse: Associated container=0x2A4F87A4 to Invite Response 487
//89/4B342D000000/SIP/Transport/sipSPITransportSendMessage: msg=0x3002DB00, addr=192.168.50.10, port=41263, sentBy_port=5060, local_addr=, is_req=0, transport=2, switch=0, callBack=0x24E21898
//89/4B342D000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//89/4B342D000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Postin
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x21144C70z 0x2114688Cz 0x2237BBB0z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24E19540z 0x24E1E528z 0x24E1F14Cz 0x24C2D350z 0x24C438B4z 0x24C56D2Cz 0x24C57DA0z 0x24DA246Cz 0x24DA2910z 0x23588E0Cz g send for msg=0x3002DB00, addr=192.168.50.10, port=41263, local_addr=, connId=2 for TCP
//89/4B342D000000/SIP/Info/sentRequestCancelDisconnecting: Sent a 487 Request Cancelled
//89/4B342D000000/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 487 Request Cancelled
Via: SIP/2.0/TCP 192.168.50.10:5060;branch=z9hG4bK3e9db6a06
From: "DEMO" <sip:200@192.168.50.10>;tag=64~7f88b1b9-f68d-4857-b8e0-e411cd112197-23099693
To: <sip:08228777303055942@192.168.50.1>;tag=FA3860-0
Date: Mon, 09 Feb 2015 07:49:34 GMT
Call-ID: 4b342d00-4d81686b-3f-a32a8c0@192.168.50.10
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Reason: Q.850;cause=16
Content-Length: 0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x4055DCD4, addr=192.168.50.10, port=41263, local_addr=, connid=2, transport=TCP
//-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:08228777303055942@192.168.50.1:5060 SIP/2.0
Via: SIP/2.0/TCP 192.168.50.10:5060;branch=z9hG4bK3d286eb43f
From: "DEMO" <sip:200@192.168.50.10>;tag=63~7f88b1b9-f68d-4857-b8e0-e411cd112197-23099691
To: <sip:08228777303055942@192.168.50.1>;tag=FA2B40-110D
Date: Mon, 09 Feb 2015 07:57:15 GMT
Call-ID: 41aac500-4d81685b-3e-a32a8c0@192.168.50.10
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: presence, kpml
Content-Length: 0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//87/41AAC5000000/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x4095E900
//-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.50.10,Port 41263, Transport 2, SentBy Port 5060
//-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
//-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.50.10,Port 41263, Transport 2, SentBy Port 5060
//87/41AAC5000000/SIP/Info/sipSPIIcpifUpdate: CallState: 2 Playout: 0 DiscTime:1640306 ConnTime 0
//87/41AAC5000000/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x4055E3B0, Tag=0x0, Call Id=87,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
//87/41AAC5000000/CCAPI/cc_api_ca
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (0/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x21144C00z 0x2114688Cz 0x2237B9F4z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24B11F34z 0x24B1271Cz 0x24AC9058z 0x24D291C4z 0x24C83A14z 0x24C42530z 0x24C55D6Cz ll_disconnect_done:
Call Disconnect Event Sent
//-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
:cc_free_feature_vsa freeing 30024D48
//-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
vsacount in free is 2
//87/41AAC5000000/SIP/State/sipSPIChangeState: 0x4095E900 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE)
//87/41AAC5000000/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x4095E900
State of The Call : STATE_DEAD
TCP Sockets Used : YES
Calling Number : 200
Called Number : 08228777303055942
Source IP Address (Sig ): 192.168.50.1
Destn SIP Req Addr:Port : 192.168.50.10:5060
Destn SIP Resp Addr:Port : 192.168.50.10:41263
Destination Name : 192.168.50.10
//87/41AAC5000000/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.50.1
Source IP Port (Media): 31226
Destn IP Address (Media): -
Destn IP Port (Media): 0
Orig Destn IP Address:Port (Media): [ - ]:0
//87/41AAC5000000/SIP/Call/sipSPICallInfo:
Disconnect Cause (CC) : 16
Disconnect Cause (SIP) : 487
//87/41AAC5000000/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing cal
%SYS-3-CPUHOG: Task is running for (4004)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x21144C68z 0x2114688Cz 0x2237BBB0z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24C7DE14z 0x24C7FE84z 0x24C42530z 0x24C55D6Cz l id 57
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[87] removed.
//87/41AAC5000000/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
//87/41AAC5000000/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x4095E900 key=41aac500-4d81685b-3e-a32a8c0@192.168.50.1008228777303055942
//87/41AAC5000000/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
//87/41AAC5000000/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x4095E900 key=41aac500-4d81685b-3e-a32a8c0@192.168.50.10FA2B40-110D
//87/41AAC5000000/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
//87/41AAC5000000/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
//87/41AAC5000000/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 4095E900
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[87]
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x4055DCD4, addr=192.168.50.10, port=41263, local_addr=, connid=2, transport=TCP
//-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:08228777303055942@192.168.50.1:5060 SIP/2.0
Via: SIP/2.0/TCP 192.168.50.10:5060;branch=z9hG4bK3e9db6a06
From: "DEMO" <sip:200@192.168.50.10>;tag=64~7f88b1b9-f68d-4857-b8e0-e411cd112197-23099693
To: <sip:08228777303055942@192.168.50.1>;tag=FA3860-0
Date: Mon, 09 Feb 2015 07:57:31 GMT
Call-ID: 4b342d00-4d81686b-3f-a32a8c0@192.168.50.10
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: presence, kpml
Content-Length: 0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//89/4B342D000000/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x4094E388
//-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.50.10,Port 41263, Transport 2, SentBy Port 5060
//-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
//-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.50.10,Port 41263, Transport 2, SentBy Port 5060
//89/4B342D000000/SIP/Info/sipSPIIcpifUpdate: CallState: 2 Playout: 0 DiscTime:1640846 ConnTime 0
//89/4B342D000000/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x4055E3B0, Tag=0x0, Call Id=89,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
//89/4B342D000000/CCAPI/cc_api_call
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (0/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x21144C68z 0x2114688Cz 0x2237B9F4z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24B11F34z 0x24B1271Cz 0x24AC9058z 0x24D291C4z 0x24C83A14z 0x24C42530z 0x24C55D6Cz _disconnect_done:
Call Disconnect Event Sent
//-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
:cc_free_feature_vsa freeing 30024B88
//-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
vsacount in free is 1
//89/4B342D000000/SIP/State/sipSPIChangeState: 0x4094E388 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE)
//89/4B342D000000/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x4094E388
State of The Call : STATE_DEAD
TCP Sockets Used : YES
Calling Number : 200
Called Number : 08228777303055942
Source IP Address (Sig ): 192.168.50.1
Destn SIP Req Addr:Port : 192.168.50.10:5060
Destn SIP Resp Addr:Port : 192.168.50.10:41263
Destination Name : 192.168.50.10
//89/4B342D000000/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.50.1
Source IP Port (Media): 20580
Destn IP Address (Media): -
Destn IP Port (Media): 0
Orig Destn IP Address:Port (Media): [ - ]:0
//89/4B342D000000/SIP/Call/sipSPICallInfo:
Disconnect Cause (CC) : 16
Disconnect Cause (SIP) : 487
//89/4B342D000000/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing c
%SYS-3-CPUHOG: Task is running for (4004)msecs, more than (2000)msecs (0/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x21144C68z 0x2114688Cz 0x2237BBB0z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24C7DE14z 0x24C7FE84z 0x24C42530z 0x24C55D6Cz all id 59
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[89] removed.
//89/4B342D000000/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
//89/4B342D000000/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x4094E388 key=4b342d00-4d81686b-3f-a32a8c0@192.168.50.1008228777303055942
//89/4B342D000000/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
//89/4B342D000000/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x4094E388 key=4b342d00-4d81686b-3f-a32a8c0@192.168.50.10FA3860-0
//89/4B342D000000/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
//89/4B342D000000/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
//89/4B342D000000/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 4094E388
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[89]ug voice ccapi inout
//-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
//88/41AAC5000000/SIP/Event/sipSPICreateRpid: Received Octet3A=0x81 -> Setting ;screen=yes ;privacy=off
//88/41AAC5000000/SIP/Info/sipSPISendInvite: Associated container=0x2A4F8014 to Invite
//88/41AAC5000000/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
//88/41AAC5000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE
//88/41AAC5000000/SIP/Transport/sipSPITransportSendMessage: msg=0x30F68B18, addr=10.1.45.20, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x0
//88/41AAC5000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//88/41AAC5000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostRequestConnection: Posting UDP conn create request for addr=10.1.45.20, port=5060, context=0x30EF3B28
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer: Wait timer set for connection=0x2A1F8830,addr=10.1.45.20, port=5060
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer:
Wait Conn Timer started for 5000 msec
//-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnInstance: Created new initiated conn=0x2A1F8830, connid=-1, addr=10.1.45.20, port=5060, local_addr=, transport=UDP
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.1.45.20, rport:5060 with laddr:
//-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x409591D8 with connection=0x2A1F8830
//88/41AAC5000000/SIP/Transport/sipSPITransportSendMessa
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x21144C4Cz 0x2114688Cz 0x2237B9F4z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24E1F2B0z 0x24C2F298z 0x24C4A640z 0x24C57A18z 0x24DA25A8z 0x24DA2920z 0x23588E0Cz 0x23588DF0z ge: Deferred sending msg=0x30F68B18
//-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
//88/41AAC5000000/SIP/Event/sipSPICreateRpid: Received Octet3A=0x81 -> Setting ;screen=yes ;privacy=off
//88/41AAC5000000/SIP/Info/sipSPISendInvite: Associated container=0x2A4F8014 to Invite
//88/41AAC5000000/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
//88/41AAC5000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE
//88/41AAC5000000/SIP/Transport/sipSPITransportSendMessage: msg=0x409CAD50, addr=10.1.45.20, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x0
//88/41AAC5000000/SIP/Transport/sipSPITransportSendMessage: Cannot proceed to send msg-0x409CAD50 immediately. Msg in send context-0x30F68B18
//88/41AAC5000000/SIP/Transport/sipSPITransportSendMessage: Enqueued msg-0x409CAD50 into transport pending Q
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 58
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWConnectionCreated: context=0x30EF3B28
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessConnCreated: gConnTab=0x30EF3B28, addr=10.1.45.20, port=5060, local_addr=, connid=2, transport=UDP
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessConnCreated: connection instance created for addr:10.1.45.20, port:5060 local_addr= local_port=60501
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportStopConnWaitTimer: Wait timer stopped for connection=0x2A1F8830,addr=10.1.45.20, port=5060
//-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnectionCreated: Moving connection=0x2A1F8830, connid=2 state to established. local_addr=, local_port=60501
//88/41AAC5000000/SIP/Transport/sipTransportPostInternalMsg: Posting Internal Msg type=0clear log
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 63
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x30F68B18, addr=10.1.45.20, port=5060, local_addr=, connId=2 for UDP
//88/41AAC5000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.1.45.20, rport:5060 with laddr:
//88/41AAC5000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x409CAD50
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x409CAD50, addr=10.1.45.20, port=5060, local_addr=, connId=2 for UDP
//88/41AAC5000000/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:08228777303055942@10.1.45.20:5060 SIP/2.0
Via: SIP/2.0/UDP 10.1.45.3:5060;branch=z9hG4bK2525A3
Remote-Party-ID: "DEMO" <sip:200@10.1.45.3>;party=calling;screen=yes;privacy=off
From: "DEMO" <sip:200@10.1.45.3>;tag=F9D7B0-D0F
To: <sip:08228777303055942@10.1.45.20>
Date: Mon, 09 Feb 2015 07:49:55 GMT
Call-ID: FBA1834E-AF6611E4-8111B06D-73276674@10.1.45.3
Supported: timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 1101710592-0000065536-0000000062-0171092160
User-Agent: Cisco-SIPGateway/IOS-12.x
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Timestamp: 1423468195
Contact: <sip:200@10.1.45.3:5060>
Expires: 180
Allow-Events: telephone-event
Max-Forwards: 69
Session-Expires: 1800
Content-Length: 0
//88/41AAC5000000/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:08228777303055942@10.1.45.20:5060 SIP/2.0
Via: SIP/2.0/UDP 10.1.45.3:5060;branch=z9hG4bK2525A3
Remote-Party-ID: "DEMO" <sip:200@10.1.45.3>;party=calling;screen=yes;privacy=off
From: "DEMO" <sip:200@10.1.45.3>;tag=F9D7B0-D0F
To: <sip:08228777303055942@10.1.45.20>
Date: Mon, 09 Feb 2015 07:49:58 GMT
Call-ID: FBA1834E-AF6611E4-8111B06D-73276674@10.1.45.3
Supported: timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 1101710592-0000065536-0000000062-0171092160
User-Agent: Cisco-SIPGateway/IOS-12.x
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Timestamp: 1423468198
Contact: <sip:200@10.1.45.3:5060>
Expires: 180
Allow-Events: telephone-event
Max-Forwards: 69
Session-Ex
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (1/0),process = CCSIP_UDP_SOCKET.
-Traceback= 0x21144C14z 0x2114688Cz 0x2237B9F4z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24C7A5B4z 0x24DA599Cz 0x24DA5B00z 0x23588E0Cz 0x23588DF0z pires: 1800
Content-Length: 0
//-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
//88/41AAC5000000/SIP/Event/sipSPICreateRpid: Received Octet3A=0x81 -> Setting ;screen=yes ;privacy=off
//88/41AAC5000000/SIP/Info/sipSPISendInvite: Associated container=0x2A4F8014 to Invite
//88/41AAC5000000/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
//88/41AAC5000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE
//88/41AAC5000000/SIP/Transport/sipSPITransportSendMessage: msg=0x30F68B18, addr=10.1.45.20, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x0
//88/41AAC5000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//88/41AAC5000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.1.45.20, rport:5060 with laddr:
//88/41AAC5000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x30F68B18
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x30F68B18, addr=10.1.45.20, port=5060, local_addr=, connId=2 for UDP
//-1/xxxxxxxxxxxx/SIP/Error/HandleUdpSocketWrites: Send failed errno 261
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 57
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWSocketException: context=0x30EF3B28
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessSocketExceptions: gConnTab=0x30EF3B28, addr=10.1.45.20, port=5060, local_addr=, connid=2, transport=UDP
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostCloseConnection: Posting UDP conn close for addr=10.1.45.20, port=5060, local_addr=, connid=2
//-1/xxxxxxxxxxxx/SIP/Transport/sipDeleteConnInstance: Deleted conn=0x2A1F8830, connid=2, addr=10.1.45.20, port=5060, local_addr=, transport=UDP
//-1/xxxxxxxxxxxx/SIP/Info/udpsock_close_connect: Socket fd: 1 closed for connid 2 with remote port: 5060
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 54
//-1/xxxxxxxxxxxx/SIP/Error/act_socket_send_msg_failure: Send Error to 10.1.45.20:5060 for transport UDP
//88/41AAC5000000/SIP/Info/sipSPIIcpifUpdate: CallState: 2 Playout: 0 DiscTime:1642255 ConnTime 0
//88/41AAC5000000/CCAPI/cc_api_call_disconnect_done:
Disposition=-11, Interface=0x4055E3B0, Tag=0x0, Call Id=88,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
//88/41AAC5000000/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
//-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
:cc_free_feature_vsa freeing 30024E28
//-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
vsacount in free is 0
//88/41AAC5000000/SIP/State/sipSPIChangeState: 0x409591D8 : State change from (STATE_SENT_INVITE, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE)
//88/41AAC5000000/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x409591D8
State of The Call : STATE_DEAD
TCP Sockets Used : NO
Calling Number : 200
Called Number : 08228777303055942
Source IP Address (Sig ): 10.1.45.3
Destn SIP Req Addr:Port : 10.1.45.20:5060
Destn SIP Resp Addr:Port : 10.1.45.20:5060
Destination Name : 10.1.45.20
//88/41AAC5000000/SIP/Call/sipSPICallInfo:
Disconnect Cause (CC) : 16
Disconnect Cause (SIP) : 200
//88/41AAC5000000/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 58
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[88] removed.
//88/41AAC5000000/SIP/Info/sipSPIUdeleteCcbFromUACTable: ****Deleting from UAC table.
//88/41AAC5000000/SIP/Info/sipSPIUdeleteCcbF
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (0/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x21144C68z 0x2114688Cz 0x2237B9F4z 0x2237A030z 0x2242E5A4z 0x2242E6B4z 0x24C7D880z 0x24C80250z 0x24E13A0Cz 0x24C55D6Cz romTable: Deleting from table. ccb=0x409591D8 key=FBA1834E-AF6611E4-8111B06D-73276674@10.1.45.3
//88/41AAC5000000/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
//88/41AAC5000000/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
//88/41AAC5000000/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 409591D8
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[88]no termin ;; terminal monitor deb ccsip messages ug voice ccapi inoutccapi inout
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIGetCallConfig: Checking Video Type Rate=-1 video_codec_allowed=1F
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIGetCallConfig: xcoder high-density disabled
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIGetCallConfig: Flow Mode set to FLOW_THROUGH
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIGetCallConfig: Media forking disabled
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIContinueNewMsgInvite: Calling name DEMO, number 200, Calling oct3 0x00, oct_3a 0x81, ext_priv 0x00, Called number 08228777303055942, oct3 0x00
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIValidateRequestUri: Not Enabled
Feb 9 07:49:17.106: //-1/41AAC5000000/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/sipSPI_ipip_IsSDPPassthruEnabled: - 0
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:0, container:2A4F7B44
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr:
Session-Expires value: 1800 refresher: none
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/Session-Timer/sipSTSLExtractMinSEHdr: Min-SE Duration: 1800
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/Session-Timer/sipSTSLInitialSRReqPeerEventGen: sending received session expires to the peer leg
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_PASS_ST_PARAMS, SE Value:1800, SE Refresher:none, Min-SE Value:1800, flags:2001
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/Session-Timer/sipSTSLMain:
SE: 1800;refresher:none peer refresher:none, flags:2001, posted event:E_STSL_INVALID_PEER_EVENT, reason:4
Configured SE:1800, Configured Min-SE:1800
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/sipSPIProcessNotifyCallInfoHeader: Callinfo parsed - Destination url = <sip:192.168.50.10:5060>, duration = 500
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found
Feb 9 07:49:17.106: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentSDP: No SDP found in inbound container
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/sipSPIDoQoSNegotiationWithNoMediaLine: Local Precondition: 1, Remote Precondition: 1
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 87, Peer CallID 0, sdp 0x2A234A68 channels 0x4095FE54
Feb 9 07:49:17.106: //87/41AAC5000000/SIP/Info/copy_channels:
callId 87 size 0 ptr 0x401FAB24)
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CCB t38 version 0 ipip_caps version 0
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Delayed media case...creating new stream
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop()
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address()
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 192.168.50.1
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 192.168.50.1
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 31226 for stream 1
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=31226
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g729r8 codecbytes :20, ptime: 20
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = 41aac500-4d81685b-3e-a32a8c0@192.168.50.10
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled: - 0
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Not Enabled
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPI_ipip_store_channel_info: negotiated dtmf not available, using dialpeer config dtmf = 0
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPIShrlCall: Check peer: 300 for Shared-Line call, callid: 87
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/ccsip_set_bearer_capability:
Bearer Capability: Speech (0x00)
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message
Feb 9 07:49:17.110: //-1/41AAC5000000/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=200
----- ccCallInfo IE subfields -----
cisco-ani=200
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=1
dest=08228777303055942
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
Feb 9 07:49:17.110: //-1/41AAC5000000/CCAPI/cc_api_call_setup_ind_common:
Interface=0x4055E3B0, Call Info(
Calling Number=200,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=08228777303055942(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
Incoming Dial-peer=300, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=87
Feb 9 07:49:17.110: //-1/41AAC5000000/CCAPI/ccCheckClipClir:
In: Calling Number=200(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
Feb 9 07:49:17.110: //-1/41AAC5000000/CCAPI/ccCheckClipClir:
Out: Calling Number=200(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
Feb 9 07:49:17.110: :cc_get_feature_vsa malloc success
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
Feb 9 07:49:17.110: cc_get_feature_vsa count is 1
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
Feb 9 07:49:17.110: :FEATURE_VSA attributes are: feature_name:0,feature_time:805457232,feature_id:82
Feb 9 07:49:17.110: //87/41AAC5000000/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=200(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=08228777303055942(TON=Unknown, NPI=Unknown))
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS_DELAYED_MEDIA
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 57 to table
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:100, container:2A4F8384
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/Session-Timer/sipSTSLValidateSessRefreshMsg: Ignoring 1xx response for session timer processing
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPISendInviteResponse: Associated container=0x2A4F8384 to Invite Response 100
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Transport/sipSPITransportSendMessage: msg=0x2A5CC788, addr=192.168.50.10, port=41263, sentBy_port=5060, local_addr=, is_req=0, transport=2, switch=0, callBack=0x0
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2A5CC788, addr=192.168.50.10, port=41263, local_addr=, connId=2 for TCP
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/State/sipSPIChangeState: 0x4095E900 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_RECD_INVITE, SUBSTATE_NONE)
Feb 9 07:49:17.110: //87/41AAC5000000/SIP/Info/sipSPIProcessContactInfo: Previous Hop 192.168.50.10:5060
Feb 9 07:49:17.110: //87/41AAC5000000/CCAPI/cc_process_call_setup_ind:
Event=0x407ACA30
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
Try with the demoted called number 08228777303055942
Feb 9 07:49:17.110: //87/41AAC5000000/CCAPI/ccCallSetContext:
Context=0x2A574B68
Feb 9 07:49:17.110: //87/41AAC5000000/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 87 with tag 300 to app "_ManagedAppProcess_Default"
Feb 9 07:49:17.110: //87/41AAC5000000/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
Feb 9 07:49:17.110: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDING
Feb 9 07:49:17.114: //87/41AAC5000000/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=200, Params=0x2A5786B0, Progress Indication=NULL(0)
Feb 9 07:49:17.114: //87/41AAC5000000/CCAPI/ccCheckClipClir:
In: Calling Number=200(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
Feb 9 07:49:17.114: //87/41AAC5000000/CCAPI/ccCheckClipClir:
Out: Calling Number=200(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
Feb 9 07:49:17.114: //87/41AAC5000000/CCAPI/ccCallSetupRequest:
Destination Pattern=0822877730......., Called Number=08228777303055942, Digit Strip=FALSE
Feb 9 07:49:17.114: //87/41AAC5000000/CCAPI/ccCallSetupRequest:
Calling Number=200(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=08228777303055942(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=DEMO
Account Number=200, Final Destination Flag=TRUE,
Guid=41AAC500-0001-0000-0000-003E0A32A8C0, Outgoing Dial-peer=200
Feb 9 07:49:17.114: //87/41AAC5000000/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=200
----- ccCallInfo IE subfields -----
cisco-ani=200
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=1
dest=08228777303055942
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
Feb 9 07:49:17.114: //87/41AAC5000000/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x4055E3B0, Interface Type=3, Destination=, Mode=0x0,
Call Params(Calling Number=200,(Calling Name=DEMO)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=08228777303055942(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=200, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
Feb 9 07:49:17.114: :cc_get_feature_vsa malloc success
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
Feb 9 07:49:17.114: cc_get_feature_vsa count is 2
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
Feb 9 07:49:17.114: :FEATURE_VSA attributes are: feature_name:0,feature_time:805457456,feature_id:83
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x409591D8) with key=[88] to table
Feb 9 07:49:17.114: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization: Entry...
Feb 9 07:49:17.114: //88/000000000000/SIP/State/sipSPIChangeState: 0x409591D8 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
Feb 9 07:49:17.114: //88/000000000000/SIP/Info/ccsip_call_setup_request: Before processing SETUP REQccb->pld.flags_ipip = 200
Feb 9 07:49:17.114: //88/000000000000/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP
Feb 9 07:49:17.114: //88/000000000000/SIP/Info/ccsip_call_setup_request:
This a IPIP call: NULL peer_channel - peer_channels = 0x0, peer_param = 0x2A4F881C, callID= 88, peer_callID = 87
Feb 9 07:49:17.114: //88/000000000000/SIP/Info/ccsip_call_setup_request: After processing SETUP REQccb->pld.flags_ipip = 400000
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : 10.1.45.20 target_port : 5060
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_SETUP
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/ccsip_call_setup_request: Incrementing call counter to [1] in dial-peer [200]
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 168)
Feb 9 07:49:17.114: //87/41AAC5000000/SIP/Info/ccsip_event_handler:
ccsip_event_handler: peer ID 88 chans 0x40ABA2D0 event 168 flags 0x40201C 0x100 0x201 data 0x40ABA2D0
Feb 9 07:49:17.114: //87/41AAC5000000/SIP/Info/ccsip_event_handler:
ccsip_event_handler: CC_EV_H245_SET_MODE: peer ID 88 chans 0x40ABA2D0 event 168 flags 0x40201C 0x100 0x201 data 0x40ABA2D0, type = 1
Feb 9 07:49:17.114: //87/41AAC5000000/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP
Feb 9 07:49:17.114: //87/41AAC5000000/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SET_MODE
Feb 9 07:49:17.114: //87/41AAC5000000/SIP/Info/Session-Timer/sipSTSLMain:
SE: 1800;refresher:none peer refresher:none, flags:2001, posted event:E_STSL_INVALID_PEER_EVENT, reason:4
Configured SE:1800, Configured Min-SE:1800
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED
Feb 9 07:49:17.114: //88/41AAC5000000/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1
Feb 9 07:49:17.114: //88/41AAC5000000/CCAPI/ccCallSetContext:
Context=0x2A578660
Feb 9 07:49:17.114: //87/41AAC5000000/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=200
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 3
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 2
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 58 to table
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIGetCallConfig: preferred_codec set[0] type :No Codec bytes: 0
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIGetCallConfig: Media forking disabled
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIGetCallConfig: Checking Video Type Rate=-1 video_codec_allowed=1F
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=87
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIGetCallConfig: xcoder high-density disabled
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIGetCallConfig: Flow Mode set to FLOW_THROUGH
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIGetCallConfig: Media forking disabled
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/preprocessSetup:
This is a not a SIGO Call -, could be DM call
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPI_ipip_call_setup: No video caps posted by peer
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPI_ipip_call_setup: xcoder high-density disabled
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPI_ipip_call_setup: Flow Mode set to FLOW_THROUGH
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:
callid 88, channels 0x0 caps 0x40AA29E4
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPI_ipip_setOptionTagInfo: Option Tag Rel1xx value is 1
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.1.45.3
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIAddMLPPServicesInfo: No MLP Info available on incoming leg
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIPreprocessUriFormat: Url cfg for 1: 2,phone-ctxt=FALSE
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIAddCiscoGcid: Gcid value not set - not adding header.
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIAddPrivacyandIdentityInfo: Removing "id" value from Privacy
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/I
spmcucsgateway#nfo/sipSPICompareHistoryInfoWithMatchedDialpeer: call-route history-info CLI not enabled
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPI_ipip_set_history_info_header: No HI header recvd from container
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPI_ipip_set_diversion_header: No diversion header recvd from container
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip
spmcucsgateway#
spmcucsgateway#
spmcucsgateway#
spmcucsgateway#_address_to_bind: calling ip_best_local_address()
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.1.45.3
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
Feb 9 07:49:17.114: //-1/xxxx
spmcucsgateway#
spmcucsgateway#
spmcucsgateway#
spmcucsgateway#xxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.1.45.3
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIUaddCcbToUACTable: ****Adding to UAC table.
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x409591D8 key=FBA1834E-AF6611E4-8111B06D-73276674@10.1.45.3
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/sipSPIUsetBillingProfile: sipCallId for billing records = FBA1834E-AF6611E4-8111B06D-73276674@10.1.45.3
Feb 9 07:49:17.114: //88/41AAC5000000/CCAPI/cc_api_call_proceeding:
Interface=0x4055E3B0, Progress Indication=NULL(0)
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.1.45.20,Port 5060, Transport 1, SentBy Port 5060
Feb 9 07:49:17.114: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:0, container:2A4F8014
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_PASS_ST_PARAMS, SE Value:1800, SE Refresher:none, Min-SE Value:1800, flags:2001
Feb 9 07:49:17.114: //88/41AAC5000000/SIP/Info/Session-Timer/sipSTSLSRReqPassPeerEventHndlr: session timer negotiated end to end
Feb 9 07:49:17.118: //88/41AAC5000000/SIP/Info/Session-Timer/sipSTSLMain:
SE: 1800;refresher:none peer refresher:none, flags:2120, posted event:E_STSL_PASS_ST_PARAMS, reason:4
Configured SE:1800, Configured Min-SE:1800
Feb 9 07:49:17.118: //88/41AAC5000000/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 0 event
Feb 9 07:49:17.118: //88/41AAC5000000/SIP/Info/sipSPI_ipip_GetPassthruDataFromTdContainer: Could not get any elements from TD Container
Feb 9 07:49:17.118: //88/41AAC5000000/SIP/Info/sipSPI_ipip_GetPassthruDataFromTdContainer: Could not get any elements from TD Container
Feb 9 07:49:17.118: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIgetRegistrarHost: registrar is not configured
Feb 9 07:49:17.118: //88/41AAC5000000/SIP/Event/sipSPICreateRpid: Received Octet3A=0x81 -> Setting ;screen=yes ;privacy=off
Feb 9 07:49:17.118: //88/41AAC5000000/SIP/Info/sipSPISendInvite: Associated container=0x2A4F8014 to Invite
Feb 9 07:49:17.118: //88/41AAC5000000/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
Feb 9 07:49:17.118: //88/41AAC5000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE
Feb 9 07:49:17.118: //88/41AAC5000000/SIP/Transport/sipSPITransportSendMessage: msg=0x3002D9F4, addr=10.1.45.20, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x24E20C4C
Feb 9 07:49:17.118: //88/41AAC5000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
Feb 9 07:49:17.118: //88/41AAC5000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
Feb 9 07:49:17.118: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostRequestConnection: Posting UDP conn create request for addr=10.1.45.20, port=5060, context=0x30EF3B28
Feb 9 07:49:17.118: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer: Wait timer set for connection=0x40695E28,addr=10.1.45.20, port=5060
Feb 9 07:49:17.118: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSe