Cisco 9971 phone cant establish call via sip trunk

rajesh.kumar · ‎11-04-2013

Hi

We have CUCM 9.1 and 9971 and 7945 phones are registered.

We have SIP trunk to FreePBX (Asterisk). All other Cisco 79xx serias phones can make call across the SIP trunk to the extension on

FreePBX (Asterisk) , except Cisco 9971 IP phones.

I have tried with disabling "video capabilies" on 9971 phone. Also "Advertise 722" disabled on 9971. Still didn't work.

When I make call across SIP trunk. I am getting busy tone. But other Cisco 79xx phones can call same extension across the same SIP trunk...!

only 9971 phone cant call extension across the sip trunk.

9971 Phone extension is 200 and I am Calling 901 across SIP trunk.

At CUCM RTMT log I get below error,

407 Proxy Authentication Required

2013/11/04 17:48:11.917|CC|OFFERED|31263163|31263164|200|901|901|SEPF84F57959B25|CONF_BRDG

2013/11/04 17:48:11.917|SIPT|31263164|UDP|OUT|192.168.25.30|5060|CONF_BRDG|192.168.25.25|5060|1,100,13,1.371^*^*|8797|bd2ce500-2771a59b-2ed-1e19a8c0@192.168.25.30|INVITE

2013/11/04 17:48:11.918|SIPT|31263164|UDP|IN|192.168.25.30|5060|CONF_BRDG|192.168.25.25|5060|1,100,238,1.2391^192.168.25.25^*|8798|bd2ce500-2771a59b-2ed-1e19a8c0@192.168.25.30|407 Proxy Authentication Required

2013/11/04 17:48:11.919|SIPT|31263164|UDP|OUT|192.168.25.30|5060|CONF_BRDG|192.168.25.25|5060|1,100,238,1.2391^192.168.25.25^*|8799|bd2ce500-2771a59b-2ed-1e19a8c0@192.168.25.30|ACK

2013/11/04 17:48:11.920|SIPL|31263163|TCP|OUT|192.168.25.30|5060|SEPF84F57959B25|192.168.25.122|51349|1,100,238,1.2391^192.168.25.25^*|8800|f84f5795-9b250009-520a461e-7b60cd8c@192.168.25.122|407 Proxy Authentication Required

2013/11/04 17:48:11.966|SIPL|31263163|TCP|IN|192.168.25.30|5060|SEPF84F57959B25|192.168.25.122|51349|1,100,13,84.36^192.168.25.122^*|8803|f84f5795-9b250009-520a461e-7b60cd8c@192.168.25.122|ACK

Attached some part of SDL logs

From: "TEST" <sip:200@192.168.25.30>;tag=3241~1df8cd1c-1453-4df4-a4b4-33afcc6c21ac-31263143

To: <sip:901@192.168.25.25>

Date: Mon, 04 Nov 2013 13:34:16 GMT

Call-ID: cb7a0180-2771a258-2da-1e19a8c0@192.168.25.30

Supported: timer,resource-priority,replaces

Min-SE: 1800

User-Agent: Cisco-CUCM9.1

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

CSeq: 101 INVITE

Expires: 180

Allow-Events: presence, kpml

Supported: X-cisco-srtp-fallback,X-cisco-original-called

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

Cisco-Guid: 3413770624-0000065536-0000000122-0504998080

Session-Expires: 1800

P-Asserted-Identity: "TEST" <sip:200@192.168.25.30>

Remote-Party-ID: "TEST" <sip:200@192.168.25.30>;party=calling;screen=yes;privacy=off

Contact: <sip:200@192.168.25.30:5060>

Max-Forwards: 69

Content-Length: 0

00128071.001 |17:34:16.034 |AppInfo |EnvProcessUdpPort - EnvProcessUdpHandler::fireSignal() varId = 0

00128071.002 |17:34:16.034 |AppInfo |EnvProcessUdpHandler::fireSignal - SEND: index = 0, handler = 0xb2d84d18

00128071.003 |17:34:16.034 |AppInfo |EnvProcessUdpPort::fireSignal - SEND, destination = 192.168.25.25:5060

00128071.004 |17:34:16.034 |AppInfo |EnvProcessUdpPort - EnvProcessUdpHandler::send(buff, 1035, 192.168.25.25:5060)

00128072.000 |17:34:16.035 |AppInfo |EnvProcessUdpHandler::handle_input - handle = 332

00128073.000 |17:34:16.035 |AppInfo |EnvProcessUdpHandler::handle_input Status: 0, Id: 0

00128074.001 |17:34:16.035 |AppInfo |//SIP/SIPUdp/wait_UdpDataInd: Incoming SIP UDP message size 564 from 192.168.25.25:[5060]:

[8566,NET]

SIP/2.0 407 Proxy Authentication Required

Via: SIP/2.0/UDP 192.168.25.30:5060;branch=z9hG4bK34e4a3d6bab;received=192.168.25.30

From: "TEST" <sip:200@192.168.25.30>;tag=3241~1df8cd1c-1453-4df4-a4b4-33afcc6c21ac-31263143

To: <sip:901@192.168.25.25>;tag=as0b9cf958

Call-ID: cb7a0180-2771a258-2da-1e19a8c0@192.168.25.30

CSeq: 101 INVITE

User-Agent: Asterisk PBX

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY

Supported: replaces

Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="6618aa4e"

Content-Length: 0

00128075.001 |17:34:16.035 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE)

00128075.002 |17:34:16.035 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=(nil)

00128075.003 |17:34:16.035 |AppInfo |//SIP/Stack/Info/0x10903a10/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX

00128075.004 |17:34:16.035 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_TRYING value=500 retries=6

00128075.005 |17:34:16.035 |AppInfo |//SIP/Stack/Transport/0x10903a10/sipSPISendAck: Sending ACK to the transport layer

00128075.006 |17:34:16.035 |AppInfo |//SIP/Stack/Transport/0x10903a10/sipSPITransportSendMessage: msg=0xb19669a0, addr=192.168.25.25, port=5060, sentBy_port=0, is_req=1, transp

00128075.007 |17:34:16.035 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: gcb=0x10903a10 is already on connection=0xfc55310 context_list

00128075.008 |17:34:16.035 |AppInfo |//SIP/Stack/Transport/0x10903a10/sipTransportLogicSendMsg: Set to send the msg=0xb19669a0

00128075.009 |17:34:16.035 |AppInfo |//SIP/Stack/Transport/0x10903a10/sipTransportPostSendMessage: Posting send for msg=0xb19669a0, addr=192.168.25.25, port=5060, connId=0 for U

00128075.010 |17:34:16.035 |AppInfo |//SIP/Stack/Error/0x10903a10/sipSPIHandleAuthChallenge: Error getting credentials

00128075.011 |17:34:16.035 |AppInfo |//SIP/Stack/Error/0x10903a10/act_sentinvite_new_message: Error handling AuthenticationChallenge

00128075.012 |17:34:16.035 |AppInfo |//SIP/Stack/States/0x10903a10/sipSPIChangeState: 0x10903a10 : State change from (STATE_SENT_INVITE, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)

00128075.013 |17:34:16.035 |AppInfo |//SIP/Stack/Info/0x10903a10/ccsip_set_cc_cause_for_spi_err: Categorized cause:47, category:181

00128075.014 |17:34:16.035 |AppInfo |//SIP/Stack/Info/0x10903a10/sipSPIInitiateDisconnect: Initiate call disconnect(47) for outgoing call

00128076.001 |17:34:16.035 |AppInfo |//SIP/SIPUdp/wait_SdlSPISignal: Outgoing SIP UDP message to 192.168.25.25:[5060]:

[8567,NET]

ACK sip:901@192.168.25.25:5060 SIP/2.0

Via: SIP/2.0/UDP 192.168.25.30:5060;branch=z9hG4bK34e4a3d6bab

From: "TEST" <sip:200@192.168.25.30>;tag=3241~1df8cd1c-1453-4df4-a4b4-33afcc6c21ac-31263143

To: <sip:901@192.168.25.25>;tag=as0b9cf958

Date: Mon, 04 Nov 2013 13:34:16 GMT

Call-ID: cb7a0180-2771a258-2da-1e19a8c0@192.168.25.30

Max-Forwards: 70

CSeq: 101 ACK

Allow-Events: presence, kpml

Content-Length: 0

00128075.015 |17:34:16.035 |AppInfo |//SIP/SIPHandler/ccbId=3241/scbId=0/ccsip_api_call_disconnected: ccb->cc_disc_cause (47); ccb->sip_disc_cause(407)

00128075.016 |17:34:16.035 |AppInfo |//SIP/SIPHandler/ccbId=3241/scbId=0/findDevicePID: Routed to SIPD by ccbId/scbId

00128077.001 |17:34:16.035 |AppInfo |EnvProcessUdpPort - EnvProcessUdpHandler::fireSignal() varId = 0

00128077.002 |17:34:16.035 |AppInfo |EnvProcessUdpHandler::fireSignal - SEND: index = 0, handler = 0xb2d84d18

00128077.003 |17:34:16.035 |AppInfo |EnvProcessUdpPort::fireSignal - SEND, destination = 192.168.25.25:5060

00128075.017 |17:34:16.035 |AppInfo |//SIP/Stack/States/0x10903a10/sipSPIChangeState: 0x10903a10 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)

00128077.004 |17:34:16.035 |AppInfo |EnvProcessUdpPort - EnvProcessUdpHandler::send(buff, 427, 192.168.25.25:5060)

00128078.001 |17:34:16.035 |AppInfo |SIPD(38) - getKeyBasedOnCiAndBranch: AddressingElement branch is 0 and ci is 31263143 mapKey is 31263143

00128078.002 |17:34:16.035 |AppInfo |SIPD(38) - getCdpcPidGivenCcbidAndCi: found Cdpc Pid (1,100,75,296) for mapKey 31263143

00128079.001 |17:34:16.035 |AppInfo |SIPCdpc(296) - tryAnotherDynamicAddr: isDynamicTrunk 0

00128079.002 |17:34:16.035 |AppInfo |ViprUtils::uploadVCRifRequired VcrUploadNeeded[1] FeatureData NOT added

00128079.003 |17:34:16.035 |AppInfo |SIPCdpc(296) - uploadVCRifRequired: VcrUploadNeeded 1

00128080.000 |17:34:16.035 |SdlSig |CcDisconnInd |wait |Cc(1,100,213,1) |SIPCdpc(1,100,75,296) |1,100,238,1.2356^192.168.25.25^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI=31263143 CI.branch=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 cv=134217749 globalDisconnect=F FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=true TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName=

00128081.000 |17:34:16.035 |SdlSig |CcDisconnInd |tcc_transit_call_proceeding5 |Cdcc(1,100,212,170) |Cc(1,100,213,1) |1,100,238,1.2356^192.168.25.25^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI=31263143 CI.branch=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 cv=134217749 globalDisconnect=F FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=true TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName=

00128081.001 |17:34:16.035 |AppInfo |Cdcc::isStaticTransactionApplicable

00128081.002 |17:34:16.035 |AppInfo |processCCMFeatureData: operationIeIdd=0

00128083.000 |17:34:16.035 |SdlSig |AuDisconnectRequest |wait |ConnectionManager(1,100,207,1) |MatrixControl(1,100,135,159) |1,100,238,1.2356^192.168.25.25^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI1=31263142 CI2=31263143 sc=0 disconnType=1 ssReason=0 clearType=0 IF1Created=F IF2Created=F party1.mMediaCoordinatorNodeId=0 party2.mMediaCoordinatorNodeId=0 party1.dtmCall=0 party2.dtmCall=0 reconnectPending=F forceStop=F

00128083.001 |17:34:16.035 |AppInfo |!!ERROR!! -ConnectionManager- wait_AuDisconnectRequest :CI NOT FOUND IN TABLE,CI(31263142,31263143),discType=1,IFCreated(0,0),PID(0-0,0-0),IFHandling(0,0),MCNode(0,0)

00128084.000 |17:34:16.035 |SdlSig |AuDisconnectReply |dissolving |MatrixControl(1,100,135,159) |ConnectionManager(1,100,207,1) |1,100,238,1.2356^192.168.25.25^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI1=31263142 CI2=31263143 sc=245 disconnType=1 ssReason=0 clearType=0 IF1Created=F IF2Created=F party1.mMediaCoordinatorNodeId=0 party2.mMediaCoordinatorNodeId=0 party1.dtmCall=0 party2.dtmCall=0 reconnectPending=F forceStop=F

00128084.001 |17:34:16.035 |AppInfo |MatrixControl:updatePartyMediaCoordinatorNodeId: party1 videoCapable=1, party 2 videocapable=1

00128084.002

Dennis Mink · ‎11-04-2013

set your asterisk to allow anonymous connections from CUCM.

=============================
Please remember to rate useful posts, by clicking on the stars below.

=============================

Please remember to rate useful posts, by clicking on the stars below.

rajesh.kumar · ‎11-12-2013

Hi

It is still not working even after setting asterisk to allow anonymous connections from CUCM.

only 9971/video phones are not able to make calls through trunk.

Other IP phones (79xx) are able to make call thriugh sip trunk.

any suggestion ?

Rgds

Rajesh

rajesh.kumar · ‎11-16-2013

Hi

Any suggestion on the issue ?

Rgds

Rajesh Kumar

Christian Isla · ‎03-06-2014

Looks like SDP is missing from your INVITE. Enable MTP, this might help.

Nishant Savalia · ‎03-07-2014

Hi Rajesh,

Are you facing this issue for Incoming call as well?

Please provide detail trace from CUCM and also let us know the call flow.. how it is?

Regards,

Nishant Savalia

Regards, Nishant Savalia