SIP trunking: Avaya IP Office 500 and Cisco Call Manager

[Frank85]

Hi,

I was wondering if anyone out there may be able to assist me in attempting to complete a SIP trunk to a Cisco Call Manager from an Avaya IP Office 500. So far, I am able to sucessfully call from any Avaya Phone on the IP Office to any extention on the CCM, but I cannot complete any calls from the CCM to the IPO 500. Here is a sample debug output from a failed call that looks like it should work to me. Have I overlooked anything?


*Sep 5 07:52:36.427: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 55
*Sep 5 07:52:36.427: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Sep 5 07:52:36.431: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x66250CC8, addr=10.10.240.1, port=36366, connid=2, transport=TCP
*Sep 5 07:52:36.431: //-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnInstance: Created new accptd conn=0x668C76C4, connid=2, addr=10.10.240.1, port=36366, transport=TCP
*Sep 5 07:52:36.431: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Sep 5 07:52:36.431: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Sep 5 07:52:36.431: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x66250CC8, addr=10.10.240.1, port=36366, connid=2, transport=TCP
*Sep 5 07:52:36.431: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:3349@10.10.30.193:5060 SIP/2.0

Date: Thu, 05 Sep 2013 08:18:43 GMT

Call-Info: <sip:10.10.240.1:5060>;method="NOTIFY;Event=telephone-event;Duration=500"

Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY

From: "Majdi Sweis" <sip:2888@10.10.240.1>;tag=ed8670f9-bccc-48ab-a850-c066054d2648-50620776

Allow-Events: presence, kpml

P-Asserted-Identity: "Majdi Sweis" <sip:2888@10.10.240.1>

Supported: timer,resource-priority,replaces

Min-SE: 2000

Remote-Party-ID: "Majdi Sweis" <sip:2888@10.10.240.1>;party=calling;screen=yes;privacy=off

Content-Length: 0

User-Agent: Cisco-CUCM7.0

To: <sip:3349@10.10.30.193>

Contact: <sip:2888@10.10.240.1:5060;transport=tcp>

Expires: 180

Call-ID: c5be7900-22813e63-74ff7-1f00a0a@10.10.240.1

Via: SIP/2.0/TCP 10.10.240.1:5060;branch=z9hG4bK13e4c84f1f2adf

CSeq: 101 INVITE

Session-Expires: 2000

Max-Forwards: 70




*Sep 5 07:52:36.431: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Sep 5 07:52:36.431: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x6579676C) with key=[2] to table
*Sep 5 07:52:36.431: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.10.240.1,Port 36366, Transport 2, SentBy Port 5060
*Sep 5 07:52:36.431: //-1/F6CD57488007/SIP/State/sipSPIChangeState: 0x6579676C : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
*Sep 5 07:52:36.431: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.10.240.1,Port 36366, Transport 2, SentBy Port 5060
*Sep 5 07:52:36.431: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
*Sep 5 07:52:36.431: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.10.240.1,Port 36366, Transport 2, SentBy Port 5060
*Sep 5 07:52:36.435: //-1/F6CD57488007/SIP/Info/sipSPISetInfoFromRpid: Received current remote name: Majdi Sweis, current remote number: 2888
*Sep 5 07:52:36.435: //-1/F6CD57488007/SIP/Info/sipSPISetInfoFromRpid: Received ;screen=yes ;privacy=off -> Setting Octet3A 0x81, extended_privacy 0x00
*Sep 5 07:52:36.435: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
*Sep 5 07:52:36.435: //-1/F6CD57488007/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
*Sep 5 07:52:36.435: //-1/F6CD57488007/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x6579676C key=c5be7900-22813e63-74ff7-1f00a0a@10.10.240.13349
*Sep 5 07:52:36.435: //-1/F6CD57488007/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id
*Sep 5 07:52:36.435: //-1/F6CD57488007/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 3349
*Sep 5 07:52:36.435: //-1/F6CD57488007/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 2888
*Sep 5 07:52:36.435: //-1/F6CD57488007/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name Majdi Sweis, number 2888, Calling oct3 0x00, oct_3a 0x81, Called number 3349
*Sep 5 07:52:36.439: ccDumpTdRequestDataSip:
*Sep 5 07:52:36.439: reqURI=sip:3349@10.10.30.193:5060
*Sep 5 07:52:36.439: calling_urip=sip:2888@10.10.240.1
*Sep 5 07:52:36.439: url_dump_header_line_avpair:
*Sep 5 07:52:36.439: num_headers = 19
*Sep 5 07:52:36.439: headers[0].linep = Date:Thu, 05 Sep 2013 08:18:43 GMT, len = 34
*Sep 5 07:52:36.439: data.attr.datap = Date:Thu, 05 Sep 2013 08:18:43 GMT, len = 4
*Sep 5 07:52:36.439: data.value.datap = Thu, 05 Sep 2013 08:18:43 GMT, len = 29
*Sep 5 07:52:36.439: headers[1].linep = Call-Info:<sip:10.10.240.1:5060>;method="NOTIFY;Event=telephone-event;Duration=500", len = 83
*Sep 5 07:52:36.439: data.attr.datap = Call-Info:<sip:10.10.240.1:5060>;method="NOTIFY;Event=telephone-event;Duration=500", len = 9
*Sep 5 07:52:36.439: data.value.datap = <sip:10.10.240.1:5060>;method="NOTIFY;Event=telephone-event;Duration=500", len = 73
*Sep 5 07:52:36.439: headers[2].linep = Allow:INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, len = 86
*Sep 5 07:52:36.439: data.attr.datap = Allow:INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, len = 5
*Sep 5 07:52:36.439: data.value.datap = INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, len = 80
*Sep 5 07:52:36.439: headers[3].linep = From:"Majdi Sweis" <sip:2888@10.10.240.1>;tag=ed8670f9-bccc-48ab-a850-c066054d2648-50620776, len = 91
*Sep 5 07:52:36.439: data.attr.datap = From:"Majdi Sweis" <sip:2888@10.10.240.1>;tag=ed8670f9-bccc-48ab-a850-c066054d2648-50620776, len = 4
*Sep 5 07:52:36.439: data.value.datap = "Majdi Sweis" <sip:2888@10.10.240.1>;tag=ed8670f9-bccc-48ab-a850-c066054d2648-50620776, len = 86
*Sep 5 07:52:36.439: headers[4].linep = Allow-Eventsresence, kpml, len = 27
*Sep 5 07:52:36.439: data.attr.datap = Allow-Eventsresence, kpml, len = 12
*Sep 5 07:52:36.439: data.value.datap = presence, kpml, len = 14
*Sep 5 07:52:36.439: headers[5].linep = P-Asserted-Identity:"Majdi Sweis" <sip:2888@10.10.240.1>, len = 56
*Sep 5 07:52:36.439: data.attr.datap = P-Asserted-Identity:"Majdi Sweis" <sip:2888@10.10.240.1>, len = 19
*Sep 5 07:52:36.439: data.value.datap = "Majdi Sweis" <sip:2888@10.10.240.1>, len = 36
*Sep 5 07:52:36.439: headers[6].linep = Supported:timer,resource-priority,replaces, len = 42
*Sep 5 07:52:36.439: data.attr.datap = Supported:timer,resource-priority,replaces, len = 9
*Sep 5 07:52:36.443: data.value.datap = timer,resource-priority,replaces, len = 32
*Sep 5 07:52:36.443: headers[7].linep = Min-SE:2000, len = 11
*Sep 5 07:52:36.443: data.attr.datap = Min-SE:2000, len = 6
*Sep 5 07:52:36.443: data.value.datap = 2000, len = 4
*Sep 5 07:52:36.443: headers[8].linep = Remote-Party-ID:"Majdi Sweis" <sip:2888@10.10.240.1>;party=calling;screen=yes;privacy=off, len = 89
*Sep 5 07:52:36.443: data.attr.datap = Remote-Party-ID:"Majdi Sweis" <sip:2888@10.10.240.1>;party=calling;screen=yes;privacy=off, len = 15
*Sep 5 07:52:36.443: data.value.datap = "Majdi Sweis" <sip:2888@10.10.240.1>;party=calling;screen=yes;privacy=off, len = 73
*Sep 5 07:52:36.443: headers[9].linep = Content-Length:0, len = 16
*Sep 5 07:52:36.443: data.attr.datap = Content-Length:0, len = 14
*Sep 5 07:52:36.443: data.value.datap = 0, len = 1
*Sep 5 07:52:36.443: headers[10].linep = User-Agent:Cisco-CUCM7.0, len = 24
*Sep 5 07:52:36.443: data.attr.datap = User-Agent:Cisco-CUCM7.0, len = 10
*Sep 5 07:52:36.443: data.value.datap = Cisco-CUCM7.0, len = 13
*Sep 5 07:52:36.443: headers[11].linep = To:<sip:3349@10.10.30.193>, len = 26
*Sep 5 07:52:36.443: data.attr.datap = To:<sip:3349@10.10.30.193>, len = 2
*Sep 5 07:52:36.443: data.value.datap = <sip:3349@10.10.30.193>, len = 23
*Sep 5 07:52:36.443: headers[12].linep = Contact:<sip:2888@10.10.240.1:5060;transport=tcp>, len = 49
*Sep 5 07:52:36.443: data.attr.datap = Contact:<sip:2888@10.10.240.1:5060;transport=tcp>, len = 7
*Sep 5 07:52:36.443: data.value.datap = <sip:2888@10.10.240.1:5060;transport=tcp>, len = 41
*Sep 5 07:52:36.443: headers[13].linep = Expires:180, len = 11
*Sep 5 07:52:36.443: data.attr.datap = Expires:180, len = 7
*Sep 5 07:52:36.443: data.value.datap = 180, len = 3
*Sep 5 07:52:36.443: headers[14].linep = Call-ID:c5be7900-22813e63-74ff7-1f00a0a@10.10.240.1, len = 51
*Sep 5 07:52:36.443: data.attr.datap = Call-ID:c5be7900-22813e63-74ff7-1f00a0a@10.10.240.1, len = 7
*Sep 5 07:52:36.443: data.value.datap = c5be7900-22813e63-74ff7-1f00a0a@10.10.240.1, len = 43
*Sep 5 07:52:36.443: headers[15].linep = Via:SIP/2.0/TCP 10.10.240.1:5060;branch=z9hG4bK13e4c84f1f2adf, len = 61
*Sep 5 07:52:36.443: data.attr.datap = Via:SIP/2.0/TCP 10.10.240.1:5060;branch=z9hG4bK13e4c84f1f2adf, len = 3
*Sep 5 07:52:36.443: data.value.datap = SIP/2.0/TCP 10.10.240.1:5060;branch=z9hG4bK13e4c84f1f2adf, len = 57
*Sep 5 07:52:36.443: headers[16].linep = CSeq:101 INVITE, len = 15
*Sep 5 07:52:36.443: data.attr.datap = CSeq:101 INVITE, len = 4
*Sep 5 07:52:36.443: data.value.datap = 101 INVITE, len = 10
*Sep 5 07:52:36.443: headers[17].linep = Session-Expires:2000, len = 20
*Sep 5 07:52:36.443: data.attr.datap = Session-Expires:2000, len = 15
*Sep 5 07:52:36.443: data.value.datap = 2000, len = 4
*Sep 5 07:52:36.443: headers[18].linep = Max-Forwards:70, len = 15
*Sep 5 07:52:36.443: data.attr.datap = Max-Forwards:70, len = 12
*Sep 5 07:52:36.443: data.value.datap = 70, len = 2num_bodies = 0
*Sep 5 07:52:36.443: //-1/F6CD57488007/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 2888
*Sep 5 07:52:36.443: //-1/F6CD57488007/SIP/Info/sipSPIGetCallConfig: Peer tag 1 matched for incoming call
*Sep 5 07:52:36.443: //-1/F6CD57488007/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
*Sep 5 07:52:36.447: //-1/F6CD57488007/SIP/Info/sipSPIGetCallConfig: Not using Voice Class Codec
*Sep 5 07:52:36.447: //-1/F6CD57488007/SIP/Media/sipSPICopyPeerDataToCCB: Firewall traversal is not enabled
*Sep 5 07:52:36.447: //-1/F6CD57488007/SIP/Info/sipSPIGetCallConfig: xcoder high-density disabled
*Sep 5 07:52:36.447: //-1/F6CD57488007/SIP/Info/sipSPIGetCallConfig: Flow Mode set to FLOW_THROUGH
*Sep 5 07:52:36.447: //-1/F6CD57488007/SIP/Info/sipSPIContinueNewMsgInvite: Calling name Majdi Sweis, number 2888, Calling oct3 0x00, oct_3a 0x81, ext_priv 0x00, Called number 3349, oct3 0x00
*Sep 5 07:52:36.447: //-1/F6CD57488007/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE
*Sep 5 07:52:36.447: //-1/F6CD57488007/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
*Sep 5 07:52:36.447: //2/F6CD57488007/SIP/Info/sipSPINegotiateSessionExpires: Min-SE Header: 2000
*Sep 5 07:52:36.447: //2/F6CD57488007/SIP/Info/sipSPINegotiateSessionExpires:
Session-Expires value: 2000 refresher: 3
*Sep 5 07:52:36.447: //2/F6CD57488007/SIP/Info/sipSPI_ipip_Add_SessionExpiresParamsToContainer: Session-refresh parameters added to container minse = 2000 session expire = 2000 refresher = 3
*Sep 5 07:52:36.447: //2/F6CD57488007/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
*Sep 5 07:52:36.447: //2/F6CD57488007/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container
*Sep 5 07:52:36.447: //2/F6CD57488007/SIP/Info/sipSPIProcessNotifyCallInfoHeader: Callinfo parsed - Destination url = <sip:10.10.240.1:5060>, duration = 500

*Sep 5 07:52:36.447: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentSDP: No SDP found in inbound container
*Sep 5 07:52:36.447: //2/F6CD57488007/SIP/Info/sipSPIDoQoSNegotiationWithNoMediaLine: Entry
*Sep 5 07:52:36.447: //2/F6CD57488007/SIP/Info/sipSPIDoQoSNegotiationWithNoMediaLine: Local Precondition: 1, Remote Precondition: 1
*Sep 5 07:52:36.447: //2/F6CD57488007/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
*Sep 5 07:52:36.447: //2/F6CD57488007/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 2, sdp 0x6708B010 channels 0x657979E0
*Sep 5 07:52:36.447: //2/F6CD57488007/SIP/Info/copy_channels:
callId 2 size 0 ptr 0x65A299CC)
*Sep 5 07:52:36.447: //2/F6CD57488007/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Delayed media case...creating new stream
*Sep 5 07:52:36.447: //2/F6CD57488007/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.10.30.193
*Sep 5 07:52:36.447: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 18648 for stream 1
*Sep 5 07:52:36.447: //2/F6CD57488007/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=18648
*Sep 5 07:52:36.451: //2/F6CD57488007/SIP/Media/sipSPIAddSDPMediaPayload: Preferred method of dtmf relay is: 6, with payload: 101
*Sep 5 07:52:36.451: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
*Sep 5 07:52:36.451: //2/F6CD57488007/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = c5be7900-22813e63-74ff7-1f00a0a@10.10.240.1
*Sep 5 07:52:36.451: //2/F6CD57488007/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo
*Sep 5 07:52:36.451: //2/F6CD57488007/SIP/Info/sipSPI_ipip_store_channel_info: negotiated dtmf not available, using dialpeer config dtmf = 6
*Sep 5 07:52:36.451: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
*Sep 5 07:52:36.451: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
*Sep 5 07:52:36.451: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message

*Sep 5 07:52:36.451: //2/F6CD57488007/SIP/Info/ccsip_set_bearer_capability:
Bearer Capability: Speech (0x00)
*Sep 5 07:52:36.451: //2/F6CD57488007/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS_DELAYED_MEDIA
*Sep 5 07:52:36.451: //2/F6CD57488007/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 2 to table
*Sep 5 07:52:36.455: //2/F6CD57488007/SIP/Transport/sipSPITransportSendMessage: msg=0x67073554, addr=10.10.240.1, port=36366, sentBy_port=5060, is_req=0, transport=2, switch=0, callBack=0x00000000
*Sep 5 07:52:36.455: //2/F6CD57488007/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Sep 5 07:52:36.455: //2/F6CD57488007/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Sep 5 07:52:36.455: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x67073554, addr=10.10.240.1, port=36366, connId=2 for TCP
*Sep 5 07:52:36.455: //2/F6CD57488007/SIP/State/sipSPIChangeState: 0x6579676C : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_RECD_INVITE, SUBSTATE_NONE)
*Sep 5 07:52:36.455: //2/F6CD57488007/SIP/Info/sipSPIProcessContactInfo: Previous Hop 10.10.240.1:5060
*Sep 5 07:52:36.459: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying

Via: SIP/2.0/TCP 10.10.240.1:5060;branch=z9hG4bK13e4c84f1f2adf

From: "Majdi Sweis" <sip:2888@10.10.240.1>;tag=ed8670f9-bccc-48ab-a850-c066054d2648-50620776

To: <sip:3349@10.10.30.193>

Date: Thu, 05 Sep 2013 07:52:36 GMT

Call-ID: c5be7900-22813e63-74ff7-1f00a0a@10.10.240.1

CSeq: 101 INVITE

Allow-Events: telephone-event

Server: Cisco-SIPGateway/IOS-12.x

Content-Length: 0




*Sep 5 07:52:36.459: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDING
*Sep 5 07:52:36.463: //2/F6CD57488007/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call.
*Sep 5 07:52:36.463: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
*Sep 5 07:52:36.463: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 3
*Sep 5 07:52:36.463: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 7
*Sep 5 07:52:36.463: //2/F6CD57488007/SIP/Info/act_recdinvite_disconnect: Performing disconnect
*Sep 5 07:52:36.463: //2/F6CD57488007/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table.
*Sep 5 07:52:36.463: //2/F6CD57488007/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x6579676C key=c5be7900-22813e63-74ff7-1f00a0a@10.10.240.1488070-A6F
*Sep 5 07:52:36.467: //2/F6CD57488007/SIP/Info/sipSPISendInviteResponse: Associated container=0x657D5C04 to Invite Response 404
*Sep 5 07:52:36.467: //2/F6CD57488007/SIP/Transport/sipSPITransportSendMessage: msg=0x670507D0, addr=10.10.240.1, port=36366, sentBy_port=5060, is_req=0, transport=2, switch=0, callBack=0x6131C2BC
*Sep 5 07:52:36.467: //2/F6CD57488007/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Sep 5 07:52:36.467: //2/F6CD57488007/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Sep 5 07:52:36.467: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x670507D0, addr=10.10.240.1, port=36366, connId=2 for TCP
*Sep 5 07:52:36.467: //2/F6CD57488007/SIP/Info/sentErrResDisconnecting: Sent an 3456XX Error Response
*Sep 5 07:52:36.467: //2/F6CD57488007/SIP/State/sipSPIChangeState: 0x6579676C : State change from (STATE_RECD_INVITE, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)
*Sep 5 07:52:36.467: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 404 Not Found

Via: SIP/2.0/TCP 10.10.240.1:5060;branch=z9hG4bK13e4c84f1f2adf

From: "Majdi Sweis" <sip:2888@10.10.240.1>;tag=ed8670f9-bccc-48ab-a850-c066054d2648-50620776

To: <sip:3349@10.10.30.193>;tag=488070-A6F

Date: Thu, 05 Sep 2013 07:52:36 GMT

Call-ID: c5be7900-22813e63-74ff7-1f00a0a@10.10.240.1

CSeq: 101 INVITE

Allow-Events: telephone-event

Server: Cisco-SIPGateway/IOS-12.x

Reason: Q.850;cause=1

Content-Length: 0




*Sep 5 07:52:36.471: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Sep 5 07:52:36.471: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
*Sep 5 07:52:36.471: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x66250CC8, addr=10.10.240.1, port=36366, connid=2, transport=TCP
*Sep 5 07:52:36.471: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:3349@10.10.30.193:5060 SIP/2.0

Date: Thu, 05 Sep 2013 08:18:43 GMT

From: "Majdi Sweis" <sip:2888@10.10.240.1>;tag=ed8670f9-bccc-48ab-a850-c066054d2648-50620776

Allow-Events: presence, kpml

Content-Length: 0

To: <sip:3349@10.10.30.193>;tag=488070-A6F

Call-ID: c5be7900-22813e63-74ff7-1f00a0a@10.10.240.1

Via: SIP/2.0/TCP 10.10.240.1:5060;branch=z9hG4bK13e4c84f1f2adf

CSeq: 101 ACK

Max-Forwards: 70




*Sep 5 07:52:36.471: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Sep 5 07:52:36.475: //2/F6CD57488007/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x6579676C
*Sep 5 07:52:36.475: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.10.240.1,Port 36366, Transport 2, SentBy Port 5060
*Sep 5 07:52:36.475: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
*Sep 5 07:52:36.475: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.10.240.1,Port 36366, Transport 2, SentBy Port 5060
*Sep 5 07:52:36.475: //2/F6CD57488007/SIP/Info/sipSPIIcpifUpdate: CallState: 2 Playout: 0 DiscTime:475148 ConnTime 0
*Sep 5 07:52:36.475: //2/F6CD57488007/SIP/State/sipSPIChangeState: 0x6579676C : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE)
*Sep 5 07:52:36.475: //2/F6CD57488007/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x6579676C
State of The Call : STATE_DEAD
TCP Sockets Used : YES
Calling Number : 2888
Called Number : 3349
Source IP Address (Sig ): 10.10.30.193
Destn SIP Req Addrort : 10.10.240.1:5060
Destn SIP Resp Addrort : 10.10.240.1:36366
Destination Name : 10.10.240.1

*Sep 5 07:52:36.475: //2/F6CD57488007/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): 10.10.30.193
Source IP Port (Media): 18648
Destn IP Address (Media): -
Destn IP Port (Media): 0
Orig Destn IP Addressort (Media): [ - ]:0

*Sep 5 07:52:36.475: //2/F6CD57488007/SIP/Call/sipSPICallInfo:
Disconnect Cause (CC) : 1
Disconnect Cause (SIP) : 404

*Sep 5 07:52:36.475: //2/F6CD57488007/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 2
*Sep 5 07:52:36.475: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[2] removed.
*Sep 5 07:52:36.479: //2/F6CD57488007/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
*Sep 5 07:52:36.479: //2/F6CD57488007/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x6579676C key=c5be7900-22813e63-74ff7-1f00a0a@10.10.240.13349
*Sep 5 07:52:36.479: //2/F6CD57488007/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
*Sep 5 07:52:36.479: //2/F6CD57488007/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x6579676C key=c5be7900-22813e63-74ff7-1f00a0a@10.10.240.1488070-A6F
*Sep 5 07:52:36.479: //2/F6CD57488007/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
*Sep 5 07:52:36.479: //2/F6CD57488007/SIP/Info/ccsip_qos_cleanup: Entry
*Sep 5 07:52:36.479: //2/F6CD57488007/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
*Sep 5 07:52:36.479: //2/F6CD57488007/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 6579676C
*Sep 5 07:52:36.479: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[2]
*Sep 5 07:52:56.055: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnAgeing: Holder=0x6701BEE4 Connection=0x668C76C4, addr=0.0.0.1, port=168488961, connid=0 has been REFRESHED
*Sep 5 07:52:56.055: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x6701BEE4,addr=10.10.240.1
Router#
Router#
Router#

I am pretty certain that the 404 not found error is the problem, but I am unsure as to whether or not that is the fault of the CCM or the IPO 500. Any help would be greatly appreciated. Thanks!!!

 

[amriddle01]

Show a trace of the Avaya side, you wouldn't ask for help in the Cisco forum with an Avaya trace I imagine. Also what is the general setup/config? That has a bearing on suggested fixes/known issues



"No problem monkey socks

 

[Frank85]

Hi ...

I follow this document when configuration:

https://devconnect.avaya.com/public/download/interop/CUCM8IPO80IPtk.pdf

can you assist me dear ???

 

[tlpeter]

Frank, Amriddle asked for a monitor trace (he was trying to help you) and you do not do that but instead you ask a new question.
This way you won't get any help as you ignore very good advise.

Make a monitor trace and post it here.
If you do not know how to make a monitor trace then i wonder if you have enough knowledge to even connect a Cisco call manager to the IPOffice.


BAZINGA!

I'm not insane, my mother had me tested!

 

[Frank85]

Hi ...

I'll go to the site now and post it here .

 

[Frank85]

Hi ...

This is the trace coming from CCM

********** SysMonitor v10.1 (43) [connected to 10.1.68.10 (Royal Wings)] **********
337901589mS PRN: Monitor Status IP 500 V2 8.1(43)
337901589mS PRN: LAW=A PRI=1, BRI=0, ALOG=4, VCOMP=42, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=5 VMAIL=1(VER=2 TYP=3) 1-X=0 CALLS=1(TOT=682)
337906703mS SIP Rx: TCP 10.10.240.1:47866 -> 10.1.68.10:5060
INVITE sip:3349@10.1.68.10:5060 SIP/2.0
Date: Sun, 08 Sep 2013 10:08:01 GMT
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
From: "Majdi Sweis" <sip:2888@10.10.240.1>;tag=ed8670f9-bccc-48ab-a850-c066054d2648-50678900
Allow-Events: presence
P-Asserted-Identity: "Majdi Sweis" <sip:2888@10.10.240.1>
Supported: timer,resource-priority,replaces
Min-SE: 2000
Remote-Party-ID: "Majdi Sweis" <sip:2888@10.10.240.1>;party=calling;screen=yes;privacy=off
Content-Length: 210
User-Agent: Cisco-CUCM7.0
To: <sip:3349@10.1.68.10>
Contact: <sip:2888@10.10.240.1:5060;transport=tcp>
Expires: 180
Content-Type: application/sdp
Call-ID: 89db1c00-22c14c81-7558d-1f00a0a@10.10.240.1
Via: SIP/2.0/TCP 10.10.240.1:5060;branch=z9hG4bK13f4a841974b7a
CSeq: 101 INVITE
Session-Expires: 2000
Max-Forwards: 70

v=0
o=CiscoSystemsCCM-SIP 2000 1 IN IP4 10.10.240.1
s=SIP Call
c=IN IP4 10.10.124.1
t=0 0
m=audio 30182 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
337906707mS SIP Call Rx: phone
INVITE sip:3349@10.1.68.10:5060 SIP/2.0
Date: Sun, 08 Sep 2013 10:08:01 GMT
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
From: "Majdi Sweis" <sip:2888@10.10.240.1>;tag=ed8670f9-bccc-48ab-a850-c066054d2648-50678900
Allow-Events: presence
P-Asserted-Identity: "Majdi Sweis" <sip:2888@10.10.240.1>
Supported: timer,resource-priority,replaces
Min-SE: 2000
Remote-Party-ID: "Majdi Sweis" <sip:2888@10.10.240.1>;party=calling;screen=yes;privacy=off
Content-Length: 210
User-Agent: Cisco-CUCM7.0
To: <sip:3349@10.1.68.10>
Contact: <sip:2888@10.10.240.1:5060;transport=tcp>
Expires: 180
Content-Type: application/sdp
Call-ID: 89db1c00-22c14c81-7558d-1f00a0a@10.10.240.1
Via: SIP/2.0/TCP 10.10.240.1:5060;branch=z9hG4bK13f4a841974b7a
CSeq: 101 INVITE
Session-Expires: 2000
Max-Forwards: 70

v=0
o=CiscoSystemsCCM-SIP 2000 1 IN IP4 10.10.240.1
s=SIP Call
c=IN IP4 10.10.124.1
t=0 0
m=audio 30182 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
337907170mS RES: Sun 8/9/2013 13:04:24 FreeMem=56318584(1) CMMsg=9 (10) Buff=5200 952 999 7423 5 Links=3717 CPU=6/8/3483/24366/28340/1
337907171mS RES2: IP 500 V2 8.1(43) Tasks=51 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=77 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=55 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034

 

[intrigrant]

Very helpfull.... not.

At your first post you should have a description the situation you have :
Which extension numbers on the IP Office, which on the the better not mentioned system, what function codes do you have etc.

Then about tracing... sysmonitor has a filter option, when we ask for a trace then we aks for a trace with the default filter AND the trace should contain the events which are necessery to identify the problem.

So, for a start-over:
What are the extension numbers in IP Office and what number is dialled on the better not mentioned system and what number does it send on the SIP line.

If you get a 404 error then the number received by IP Office is not a valid extension or group.

If programmed properly then incoming calls on SIP trunks traverse the Incoming Call Route, if you create a incoming call route with the incoming linde ID of the the better not mentioned system trunk and no DDI set but with a valid destination then ANY number coming from the the better not mentioned system would route to the ICR destination. To route incoming SIP calls to the ICR set "Local URI" to a * in the SIP>URI settings.

That is step 1 in resolving the problem.

Step 2 is to identify what number is received from the the better not mentioned system, it will be shown in systemstatus> active calls or in sysmonitor or on the phone receiving the call.
Then create a incoming call route for each extension with the correct DDI number received from the better not mentioned system, or send the ICR route without a DDI number to a shortcode altering the received number to a known number wit as action "dial extension".
But best is to alter the better not mentioned system in such a manner it sends only known numbers.