Hello,
We are converting our environment from a traditional T1 (POTS) incoming phone line to a SIP trunk on our Cisco UC520. DID numbers are configured on each circuit (DID on T1 provisioned and works fine, DID on SIP Trunk provisioned).
A quick diagram
PSTN----\ |----------|
\--------| |
/--------| C-UC520 |-------> IP Phones / CUE
IP SIP--/ |----------|
(10.10.80.252) (172.29.0.20)
Inbound calls ring a receptionist extension, then transfer to extension 4700 (auto attendant) if there is no answer. When calls come in on the PSTN line, the transfer to the AA works perfectly when the receptionist doesn't answer. Calls coming in on the SIP line ring the receptionist, but fail when attempting to transfer to the AA.
Your assistance with this would be HUGELY appreciated!
INBOUND SIP CALL: debug ccsip messages (just when the transfer occurs - phone numbers hidden to protect the innocent)
166714: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:6********4@172.29.0.20:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.80.252:5060;branch=z9hG4bK76661994
Remote-Party-ID: "6********1" <sip:6********1@10.10.80.252>;party=calling;screen=no;privacy=off
From: "6********1" <sip:6********1@10.10.80.252>;tag=DC31124-48B
To: <sip:6********4@172.29.0.20>
Date: Fri, 12 Oct 2012 18:08:13 GMT
Call-ID: 9F5C6A0D-13CE11E2-B265CFEA-48AA9F88@10.10.80.252
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 2673273716-0332272098-2992623594-1219141512
User-Agent: Cisco-SIPGateway/IOS-12.x
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Timestamp: 1350065293
Contact: <sip:6********1@10.10.80.252:5060>
Call-Info: <sip:10.10.80.252:5060>;method="NOTIFY;Event=telephone-event;Duration=2000"
Expires: 180
Allow-Events: telephone-event
Max-Forwards: 69
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 284
v=0
o=root 1142925334 1142925334 IN IP4 10.10.80.244
s=Asterisk PBX 1.8.14.0
c=IN IP4 10.10.80.252
t=0 0
m=audio 19234 RTP/AVP 0 8 3 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
166715: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.10.80.252:5060;branch=z9hG4bK76661994
From: "6********1" <sip:6********1@10.10.80.252>;tag=DC31124-48B
To: <sip:6********4@172.29.0.20>
Date: Fri, 12 Oct 2012 19:46:49 GMT
Call-ID: 9F5C6A0D-13CE11E2-B265CFEA-48AA9F88@10.10.80.252
Timestamp: 1350065293
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 101 INVITE
Allow-Events: telephone-event
Content-Length: 0
166716: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.10.80.252:5060;branch=z9hG4bK76661994
From: "6********1" <sip:6********1@10.10.80.252>;tag=DC31124-48B
To: <sip:6********4@172.29.0.20>;tag=32ACC1C8-1BAB
Date: Fri, 12 Oct 2012 19:46:49 GMT
Call-ID: 9F5C6A0D-13CE11E2-B265CFEA-48AA9F88@10.10.80.252
Timestamp: 1350065293
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 101 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Require: 100rel
RSeq: 9534
Allow-Events: telephone-event
Remote-Party-ID: "Main Line" <sip:5455@172.29.0.20>;party=called;screen=no;privacy=off
Contact: <sip:6********4@172.29.0.20:5060>
Content-Length: 0
166717: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
PRACK sip:6********4@172.29.0.20:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.80.252:5060;branch=z9hG4bK7667827
From: "6********1" <sip:6********1@10.10.80.252>;tag=DC31124-48B
To: <sip:6********4@172.29.0.20>;tag=32ACC1C8-1BAB
Date: Fri, 12 Oct 2012 18:08:13 GMT
Call-ID: 9F5C6A0D-13CE11E2-B265CFEA-48AA9F88@10.10.80.252
CSeq: 102 PRACK
RAck: 9534 101 INVITE
Allow-Events: telephone-event
Max-Forwards: 70
Content-Length: 0
166718: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.80.252:5060;branch=z9hG4bK7667827
From: "6********1" <sip:6********1@10.10.80.252>;tag=DC31124-48B
To: <sip:6********4@172.29.0.20>;tag=32ACC1C8-1BAB
Date: Fri, 12 Oct 2012 19:46:49 GMT
Call-ID: 9F5C6A0D-13CE11E2-B265CFEA-48AA9F88@10.10.80.252
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 102 PRACK
Content-Length: 0
166719: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 302 Moved Temporarily
Via: SIP/2.0/UDP 10.10.80.252:5060;branch=z9hG4bK76661994
From: "6********1" <sip:6********1@10.10.80.252>;tag=DC31124-48B
To: <sip:6********4@172.29.0.20>;tag=32ACC1C8-1BAB
Date: Fri, 12 Oct 2012 19:46:49 GMT
Call-ID: 9F5C6A0D-13CE11E2-B265CFEA-48AA9F88@10.10.80.252
Timestamp: 1350065293
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 101 INVITE
Allow-Events: telephone-event
Diversion: <sip:6********4@172.29.0.20>;reason=no-answer;counter=1
Contact: <sip:4700@172.29.0.20>
Content-Length: 0
166720: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:6********4@172.29.0.20:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.80.252:5060;branch=z9hG4bK76661994
From: "6********1" <sip:6********1@10.10.80.252>;tag=DC31124-48B
To: <sip:6********4@172.29.0.20>;tag=32ACC1C8-1BAB
Date: Fri, 12 Oct 2012 18:08:13 GMT
Call-ID: 9F5C6A0D-13CE11E2-B265CFEA-48AA9F88@10.10.80.252
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event
Content-Length: 0
INBOUND SIP CALL: debug ccsip all (just when the transfer occurs - phone numbers hidden to protect the innocent; I realize this is a little redundant)
166468: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnAgeing: Connection=0x855F9E60, addr=10.1.10.1, port=5060, connid=1 has been aged out
166469: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostCloseConnection: Posting UDP conn close for addr=10.1.10.1, port=5060, connid=1
166470: //-1/xxxxxxxxxxxx/SIP/Transport/sipDeleteConnInstance: Deleted conn=0x855F9E60, connid=1, addr=10.1.10.1, port=5060, transport=UDP
166471: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x84729F98,addr=10.1.10.1
166472: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportStopAgeingTimer: Aging timer stopped for holder=0x84729F98,addr=10.1.10.1
166473: //-1/xxxxxxxxxxxx/SIP/Transport/sipDeleteConnHolder: Deleted holder=0x84729F98, addr=10.1.10.1, count=0
166474: //-1/xxxxxxxxxxxx/SIP/Info/udpsock_close_connect: Socket fd: 1 closed for connid 1 with remote port: 5060
166475: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_call_forward:
ccsip_call_forward
166476: //2005/FDF54C6DB235/SIP/Info/ccsip_call_forward: Call forward target num 4700
166477: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_FORWARD
166478: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 28
166479: //2005/FDF54C6DB235/SIP/Info/sipSPIAddCiscoGcid: Gcid value not set - not adding header.
166480: //2005/FDF54C6DB235/SIP/Info/ccsip_spi_create_call_forward_contact_list: Calling peeridb not found
166481: //2005/FDF54C6DB235/SIP/Info/ccsip_spi_create_call_forward_contact_list: Call forward dpeer tag: 2001
166482: //2005/FDF54C6DB235/SIP/Info/ccsip_spi_add_redirect_contact: found voip peer, using session target as contact
166483: //2005/FDF54C6DB235/SIP/Info/ccsip_spi_add_redirect_contact: Calling peeridb not found
166484: //2005/FDF54C6DB235/SIP/Info/ccsip_spi_create_call_forward_contact_list: Number of redirect contacts added: 1
166485: //2005/FDF54C6DB235/SIP/Info/act_spi_call_forward:
Performing call forward
166486: //2005/FDF54C6DB235/SIP/Info/act_spi_call_forward:
Sending 3xx response
166487: //2005/FDF54C6DB235/SIP/Info/sipSPISendInviteResponse: Associated container=0x8793841C to Invite Response 302
166488: //2005/FDF54C6DB235/SIP/Transport/sipSPITransportSendMessage: msg=0x87F13D84, addr=10.10.80.252, port=50240, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x80D14908
166489: //2005/FDF54C6DB235/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
166490: //2005/FDF54C6DB235/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
166491: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x87F13D84, addr=10.10.80.252, port=5060, connId=0 for UDP
166492: //2005/FDF54C6DB235/SIP/Info/sentInviteResponseRedMovedTemp: Sent an 3456XX Error Response
166493: //2005/FDF54C6DB235/SIP/Info/sipSPIInitiateDisconnect: Initiate call disconnect(16) for incoming call
166494: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_set_release_source_for_peer: ownCallId[2005], src[6]
166495: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_set_release_source_for_peer: Failed AV set
166496: //2005/FDF54C6DB235/SIP/State/sipSPIChangeState: 0x85427250 : State change from (STATE_SENT_ALERTING, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)
166497: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 302 Moved Temporarily
Via: SIP/2.0/UDP 10.10.80.252:5060;branch=z9hG4bK7657A75
From: "6********1" <sip:6********1@10.10.80.252>;tag=DA4B8A4-1AC9
To: <sip:6********4@172.29.0.20>;tag=328E69C0-F67
Date: Fri, 12 Oct 2012 19:13:40 GMT
Call-ID: FDFB6695-13C911E2-B23BCFEA-48AA9F88@10.10.80.252
Timestamp: 1350063304
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 101 INVITE
Allow-Events: telephone-event
Diversion: <sip:6********4@172.29.0.20>;reason=no-answer;counter=1
Contact: <sip:4700@172.29.0.20>
Content-Length: 0
166498: //2005/FDF54C6DB235/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call.
166499: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
166500: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 7
166501: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 10.10.80.252:50240
166502: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
166503: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
166504: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:6********4@172.29.0.20:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.80.252:5060;branch=z9hG4bK7657A75
From: "6********1" <sip:6********1@10.10.80.252>;tag=DA4B8A4-1AC9
To: <sip:6********4@172.29.0.20>;tag=328E69C0-F67
Date: Fri, 12 Oct 2012 17:35:04 GMT
Call-ID: FDFB6695-13C911E2-B23BCFEA-48AA9F88@10.10.80.252
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event
Content-Length: 0
166505: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
166506: //2005/FDF54C6DB235/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x85427250
166507: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 10.10.80.252,Port 50240, Transport 1, SentBy Port 5060
166508: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 10.10.80.252,Port 50240, Transport 1, SentBy Port 5060
166509: //2005/FDF54C6DB235/SIP/Info/sipSPIIcpifUpdate: CallState: 2 Playout: 0 DiscTime:84821802 ConnTime 0
166510: //2005/FDF54C6DB235/SIP/State/sipSPIChangeState: 0x85427250 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE)
166511: //2005/FDF54C6DB235/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x85427250
State of The Call : STATE_DEAD
TCP Sockets Used : NO
Calling Number : 6********1
Called Number : 6********4
Source IP Address (Sig ): 172.29.0.20
Destn SIP Req Addr:Port : 10.10.80.252:5060
Destn SIP Resp Addr:Port : 10.10.80.252:50240
Destination Name : 10.10.80.252
166512: //2005/FDF54C6DB235/SIP/Call/sipSPIMediaCallInfo:
Number of Media Streams: 1
Media Stream : 1
Negotiated Codec : g711ulaw
Negotiated Codec Bytes : 160
Nego. Codec payload : 0 (tx), 0 (rx)
Negotiated Dtmf-relay : 6
Dtmf-relay Payload : 101 (tx), 101 (rx)
Source IP Address (Media): 172.29.0.20
Source IP Port (Media): 16668
Destn IP Address (Media): 10.10.80.252
Destn IP Port (Media): 19514
Orig Destn IP Address:Port (Media): 0.0.0.0:0
166513: //2005/FDF54C6DB235/SIP/Call/sipSPICallInfo:
Disconnect Cause (CC) : 16
Disconnect Cause (SIP) : 302
166514: //2005/FDF54C6DB235/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 7D5
166515: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[599] removed.
166516: //2005/FDF54C6DB235/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
166517: //2005/FDF54C6DB235/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x85427250 key=FDFB6695-13C911E2-B23BCFEA-48AA9F88@10.10.80.2526********4
166518: //2005/FDF54C6DB235/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
166519: //2005/FDF54C6DB235/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x85427250 key=FDFB6695-13C911E2-B23BCFEA-48AA9F88@10.10.80.252328E69C0-F67
166520: //2005/FDF54C6DB235/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
166521: //2005/FDF54C6DB235/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 85427250
166522: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[599]u all
