[SOLVED] Cisco 7940 401 Authorisation Failure PJSIP & Asterisk 13

felimwhiteley · April 26, 2016, 10:55am

Hi Folks,

I’ve been trying to get Cisco 7940s to auth to asterisk 13.1cert6 for a good while and with no look. Searching here I’m confident it’s not the force_rports solution. I actually set the phone to only use IP based identify and it works perfect, so it can talk to the PJSIP channel. A debug of that:

<--- Received SIP request (547 bytes) from UDP:172.16.13.212:50163 --->
REGISTER sip:172.16.12.98 SIP/2.0
Via: SIP/2.0/UDP 172.16.13.212:5061;branch=z9hG4bK11e4689c
From: <sip:21011@172.16.12.98>;tag=00119378e3d1000f2dd12cc7-7c9e5225
To: <sip:21011@172.16.12.98>
Call-ID: 00119378-e3d10003-0c33be14-4028d3f0@172.16.13.212
Max-Forwards: 70
Date: Mon, 25 Apr 2016 08:29:26 GMT
CSeq: 133 REGISTER
User-Agent: Cisco-CP7940G/8.0
Contact: <sip:21011@172.16.13.212:5061;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-00119378e3d1>";+u.sip!model.ccm.cisco.com="8"
Content-Length: 0
Expires: 3600


<--- Transmitting SIP response (521 bytes) to UDP:172.16.13.212:5061 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 172.16.13.212:5061;received=172.16.13.212;branch=z9hG4bK11e4689c
Call-ID: 00119378-e3d10003-0c33be14-4028d3f0@172.16.13.212
From: <sip:21011@172.16.12.98>;tag=00119378e3d1000f2dd12cc7-7c9e5225
To: <sip:21011@172.16.12.98>;tag=z9hG4bK11e4689c
CSeq: 133 REGISTER
WWW-Authenticate: Digest  realm="asterisk",nonce="1461572967/84e4c2d82cfa5b9be2d853c84ef4198a",opaque="331495a36d686e00",algorithm=md5,qop="auth"
Server: Asterisk PBX certified/13.1-cert6
Content-Length:  0


<--- Received SIP request (802 bytes) from UDP:172.16.13.212:50164 --->
REGISTER sip:172.16.12.98 SIP/2.0
Via: SIP/2.0/UDP 172.16.13.212:5061;branch=z9hG4bK06e56051
From: <sip:21011@172.16.12.98>;tag=00119378e3d1000f2dd12cc7-7c9e5225
To: <sip:21011@172.16.12.98>
Call-ID: 00119378-e3d10003-0c33be14-4028d3f0@172.16.13.212
Max-Forwards: 70
Date: Mon, 25 Apr 2016 08:29:26 GMT
CSeq: 134 REGISTER
User-Agent: Cisco-CP7940G/8.0
Contact: <sip:21011@172.16.13.212:5061;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-00119378e3d1>";+u.sip!model.ccm.cisco.com="8"
Authorization: Digest username="21011",realm="asterisk",uri="sip:172.16.12.98",response="bc05430d99471409778102bf057598e7",nonce="1461572967/84e4c2d82cfa5b9be2d853c84ef4198a",opaque="331495a36
d686e00",cnonce="7e41d2c2",qop=auth,nc=00000001,algorithm=md5
Content-Length: 0
Expires: 3600


<--- Transmitting SIP response (532 bytes) to UDP:172.16.13.212:5061 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 172.16.13.212:5061;received=172.16.13.212;branch=z9hG4bK06e56051
Call-ID: 00119378-e3d10003-0c33be14-4028d3f0@172.16.13.212
From: <sip:21011@172.16.12.98>;tag=00119378e3d1000f2dd12cc7-7c9e5225
To: <sip:21011@172.16.12.98>;tag=z9hG4bK06e56051
CSeq: 134 REGISTER
WWW-Authenticate: Digest  realm="asterisk",nonce="1461572967/8563c8128b3470617ab9aecf325ed638",opaque="7be1e3a03be5d665",stale=true,algorithm=md5,qop="auth"
Server: Asterisk PBX certified/13.1-cert6
Content-Length:  0

The config for the phone is:

[global]
  type=global
  debug=yes

[simpletrans]
  type=transport
  protocol=udp
  bind=172.16.12.98

21011]
  type=endpoint
  transport=simpletrans
  context=LocalSets
  device_state_busy_at=1
  disallow=all
  allow=ulaw
  allow=alaw
  auth=21011
  aors=21011
  force_rport=no

[21011]
  type=auth
  auth_type=userpass
  password=21011
  username=21011
  realm=asterisk

[21011]
  type=aor
  max_contacts=1
  qualify_frequency=135
  remove_existing=yes

I’ve logged onto the phone, verified it is using 21011 as password, I then tried to see could I calculate the Auth Digest myself, but I can’t. I have a small bit of python I use on old asterisk 1.8 and it works fine, but on 13 I can’t verify it. Do you know has this changed?

Authorization: Digest username="21011",realm="asterisk",uri="sip:172.16.12.98",response="10884aa53689ad739ac67b959cb63a28",nonce="1461572967/5384f76c473138651485651eafccb8d0",opaque="2c05c3210c530939",cnonce="471ad3e5",qop=auth,nc=00000003,algorithm=md5

Try this with

NONCE = 1461572967/5384f76c473138651485651eafccb8d0
HA1 = md5(21011:asterisk:21011)
HA2 = md5(REGISTER:sip:172.16.12.98)
Digest = md5(HA1:NONCE:HA2)

Using the example above you get the response as 19609e29f81cba92d692db2c3c7e373b which doesn’t match. I verified this check on asterisk 1.8 and it works fine but the nonce is way shorter, so I’m doing something wrong or something has changed. Perhaps which is also effecting the phone? Obviously the phone isn’t your problem but if you can shed any light it would be a great help., or if anyone with a functioning 7940 is willing to post pjsip config etc. I see hints of people getting this to work but never any follow up.

Cheers

Felim

PS: Hopefully all the code exampes etc. have escaped properly… can’t upload txt files unfortunatly

felimwhiteley · April 26, 2016, 1:07pm

Ok partially solved some of the problem. Found the newer version of the auth digest was

MD5(HA1:NONCE:nc:cnonce:auth:HA2)

which means it’s correct. So not sure why it’s 401…

felimwhiteley · April 27, 2016, 2:28pm

A debug fromt he phone, had meant to add one yesterday:

SIP Phone> [15:20:29:8655352] SIPTaskProcessListEvent: cmd = 0x0
[15:20:29:8655352] LINE 6/1: --0x00071dad--                     : SIP_REG_STATE_IDLE <- E_SIP_REG_TMR_EXPIRE
[15:20:29:8655352] LINE 6/1: sip_sm_call_cleanup                : Cleaning up the call
[15:20:29:8655353] ccsip_register_send_msg: cmd=0x161c01
[15:20:29:8655353] SIPTaskProcessListEvent: cmd = 0x161c01
[15:20:29:8655354] LINE 6/1: --0x00071c4d--                     : SIP_REG_STATE_IDLE <- E_SIP_REG_REG_REQ
[15:20:29:8655354] SIPSPISendRegister: Sending REGISTER...
[15:20:29:8655355] get_next_request_trx_index: Getting next TRX index, sent = 1
[15:20:29:8655355] get_next_request_trx_index: Got TRX(0) for sent req
[15:20:29:8655356] get_last_request_trx_index: Getting last TRX index, sent = 1
[15:20:29:8655356] get_last_request_trx_index: Got TRX(0) for sent req
[15:20:29:8655358] get_last_request_trx_index: Getting last TRX index, sent = 1
[15:20:29:8655358] get_last_request_trx_index: Got TRX(0) for sent req
[15:20:29:8655360] get_last_request_trx_index: Getting last TRX index, sent = 1
[15:20:29:8655360] get_last_request_trx_index: Got TRX(0) for sent req
[15:20:29:8655361] sipTransportSendMessage: ccb <6>: config <172.16.12.98>:<5060> - remote <0.0.0.0>:<5060>
[15:20:29:8655362] sipTransportSendMessage: Opened a one-time UDP send channel to server <172.16.12.98>:<5060>, handle = 8 local port= 0
[15:20:29:8655363] sipTransportSendMessage:Sent SIP message to <172.16.12.98>:<5060>, handle=<8>, length=<548>, message=
[15:20:29:8655363] REGISTER sip:172.16.12.98 SIP/2.0
Via: SIP/2.0/UDP 172.16.13.212:5061;branch=z9hG4bK46787ec0
From: <sip:21011@172.16.12.98>;tag=00119378e3d105b974018012-0e55abfc
To: <sip:21011@172.16.12.98>
Call-ID: 00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212
Max-Forwards: 70
Date: Wed, 27 Apr 2016 14:20:29 GMT
CSeq: 5833 REGISTER
User-Agent: Cisco-CP7940G/8.0
Contact: <sip:21011@172.16.13.212:5061;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-00119378e3d1>";+u.sip!model.ccm.cisco.com="8"
Content-Length: 0
Expires: 3600

[15:20:29:8655365] sipTransportSendMessage: Closed a one-time UDP send channel handle = 8
[15:20:29:8655365] LINE 6/1: sipTransportSendMessage            : Stopping reTx timer
Via: SIP/2.0/UDP 172.16.13.212:5061;received=172.16.13.212;branch=z9hG4bK46787ec0
Call-ID: 00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212
From: <sip:21011@172.16.12.98>;tag=00119378e3d105b974018012-0e55abfc
To: <sip:21011@172.16.12.98>;tag=z9hG4bK46787ec0
CSeq: 5833 REGISTER
WWW-Authenticate: Digest  realm="asterisk",nonce="1461766828/712c8b58adac4ef0272d69fdbb92d5e8",opaque="01c45e7c6e1406af",algorithm=md5,qop="auth"
Server: Asterisk PBX certified/13.1-cert6
Content-Length:  0

[15:20:29:8655370] SIPTaskProcessSIPMessage: Line filter: Determining destination line...
[15:20:29:8655370] get_method_request_trx_index: Getting TRX for method(REGISTER), sent = 1
[15:20:29:8655371] get_method_request_trx_index: Got TRX(0) for sent method(REGISTER)
[15:20:29:8655371] sip_sm_ccb_match_branch_cseq: Matched branch_id & CSeq
[15:20:29:8655371] SIPTaskProcessSIPMessage: Line filter: Call ID match:  Destination line = <6/1>.
[15:20:29:8655372] SIPTaskProcessSIPMessage: Received SIP response.
[15:20:29:8655373] get_method_request_trx_index: Getting TRX for method(REGISTER), sent = 1
[15:20:29:8655373] get_method_request_trx_index: Got TRX(0) for sent method(REGISTER)
[15:20:29:8655374] sipSPICheckResponse: Response match: callid=00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212, cseq=5833, cseq_method=REGISTER
[15:20:29:8655375] SIPTaskProcessSIPMessage: Stopping any outstanding reTx timers...
[15:20:29:8655376] LINE 6/1: sip_sm_check_retx_timers           : Stopping reTx timer.
(callid=00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212, cseq=5833, cseq_method=REGISTER)
[15:20:29:8655377] SIPTaskProcessSIPMessage: Recv 4xx/5xx/6xx message.
[15:20:29:8655377] LINE 6/1: --0x000728dd--                     : SIP_REG_STATE_REGISTERING <- E_SIP_REG_4xx
[15:20:29:8655378] clean_method_request_trx: Removing TRX for method(REGISTER), sent = 1
[15:20:29:8655378] clean_method_request_trx: Removed TRX(0) for method(REGISTER)
[15:20:29:8655379] LINE 6/1: ccsip_handle_ev_4xx                : SIP_REG_STATE_REGISTERING <- SIP(401)
[15:20:29:8655381] SIPSPISendRegister: Sending REGISTER...
[15:20:29:8655381] get_next_request_trx_index: Getting next TRX index, sent = 1
[15:20:29:8655382] get_next_request_trx_index: Got TRX(0) for sent req
[15:20:29:8655382] get_last_request_trx_index: Getting last TRX index, sent = 1
[15:20:29:8655383] get_last_request_trx_index: Got TRX(0) for sent req
[15:20:29:8655384] get_last_request_trx_index: Getting last TRX index, sent = 1
[15:20:29:8655385] get_last_request_trx_index: Got TRX(0) for sent req
[15:20:29:8655386] get_last_request_trx_index: Getting last TRX index, sent = 1
[15:20:29:8655387] get_last_request_trx_index: Got TRX(0) for sent req
[15:20:29:8655388] sipTransportSendMessage: ccb <6>: config <172.16.12.98>:<5060> - remote <0.0.0.0>:<5060>
[15:20:29:8655389] sipTransportSendMessage: Opened a one-time UDP send channel to server <172.16.12.98>:<5060>, handle = 8 local port= 0
[15:20:29:8655389] sipTransportSendMessage:Sent SIP message to <172.16.12.98>:<5060>, handle=<8>, length=<803>, message=
[15:20:29:8655390] REGISTER sip:172.16.12.98 SIP/2.0
Via: SIP/2.0/UDP 172.16.13.212:5061;branch=z9hG4bK4f46bf19
From: <sip:21011@172.16.12.98>;tag=00119378e3d105b974018012-0e55abfc
To: <sip:21011@172.16.12.98>
Call-ID: 00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212
Max-Forwards: 70
Date: Wed, 27 Apr 2016 14:20:29 GMT
CSeq: 5834 REGISTER
User-Agent: Cisco-CP7940G/8.0
Contact: <sip:21011@172.16.13.212:5061;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-00119378e3d1>";+u.sip!model.ccm.cisco.com="8"
Authorization: Digest username="21011",realm="asterisk",uri="sip:172.16.12.98",response="26dc26b0b2197c75121efb030bdbdb6d",nonce="1461766828/712c8b58adac4ef0272d69fdbb92d5e8",opaque="01c45e7c6e1406af",cnonce="57143cc0",qop=auth,nc=00000001,algorithm=md5
Content-Length: 0
Expires: 3600

[15:20:29:8655392] sipTransportSendMessage: Closed a one-time UDP send channel handle = 8
[15:20:29:8655392] LINE 6/1: sipTransportSendMessage            : Stopping reTx timer
[15:20:29:8655393] LINE 6/1: sipTransportSendMessage            : Starting reTx timer (500 msec)
[15:20:29:8655394] SIPTaskProcessListEvent: cmd = 0x160200
[15:20:29:8655394] SIPProcessUDPMessage: recv UDP message from <172.16.12.98>:<50195>, length=<533>, message=
[15:20:29:8655395] SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 172.16.13.212:5061;received=172.16.13.212;branch=z9hG4bK4f46bf19
Call-ID: 00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212
From: <sip:21011@172.16.12.98>;tag=00119378e3d105b974018012-0e55abfc
To: <sip:21011@172.16.12.98>;tag=z9hG4bK4f46bf19
CSeq: 5834 REGISTER
WWW-Authenticate: Digest  realm="asterisk",nonce="1461766829/97b7e166fb277b8a0d692c814ab1cc7e",opaque="40aa2af96c4aeb6d",stale=true,algorithm=md5,qop="auth"
Server: Asterisk PBX certified/13.1-cert6
Content-Length:  0

[15:20:29:8655397] SIPTaskProcessSIPMessage: Line filter: Determining destination line...
[15:20:29:8655397] get_method_request_trx_index: Getting TRX for method(REGISTER), sent = 1
[15:20:29:8655398] get_method_request_trx_index: Got TRX(0) for sent method(REGISTER)
[15:20:29:8655399] sip_sm_ccb_match_branch_cseq: Matched branch_id & CSeq
[15:20:29:8655399] SIPTaskProcessSIPMessage: Line filter: Call ID match:  Destination line = <6/1>.
[15:20:29:8655399] SIPTaskProcessSIPMessage: Received SIP response.
[15:20:30:8655401] get_method_request_trx_index: Getting TRX for method(REGISTER), sent = 1
[15:20:30:8655401] get_method_request_trx_index: Got TRX(0) for sent method(REGISTER)
[15:20:30:8655401] sipSPICheckResponse: Response match: callid=00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212, cseq=5834, cseq_method=REGISTER
[15:20:30:8655402] SIPTaskProcessSIPMessage: Stopping any outstanding reTx timers...
[15:20:30:8655404] LINE 6/1: sip_sm_check_retx_timers           : Stopping reTx timer.
(callid=00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212, cseq=5834, cseq_method=REGISTER)
[15:20:30:8655405] SIPTaskProcessSIPMessage: Recv 4xx/5xx/6xx message.
[15:20:30:8655405] LINE 6/1: --0x000728dd--                     : SIP_REG_STATE_REGISTERING <- E_SIP_REG_4xx
[15:20:30:8655406] clean_method_request_trx: Removing TRX for method(REGISTER), sent = 1
[15:20:30:8655406] clean_method_request_trx: Removed TRX(0) for method(REGISTER)
[15:20:30:8655407] LINE 6/1: ccsip_handle_ev_4xx                : SIP_REG_STATE_REGISTERING <- SIP(401)
[15:20:30:8655409] SIPSPISendRegister: Sending REGISTER...
[15:20:30:8655409] get_next_request_trx_index: Getting next TRX index, sent = 1
[15:20:30:8655410] get_next_request_trx_index: Got TRX(0) for sent req
[15:20:30:8655410] get_last_request_trx_index: Getting last TRX index, sent = 1
[15:20:30:8655410] get_last_request_trx_index: Got TRX(0) for sent req
[15:20:30:8655412] get_last_request_trx_index: Getting last TRX index, sent = 1
[15:20:30:8655412] get_last_request_trx_index: Got TRX(0) for sent req
[15:20:30:8655414] get_last_request_trx_index: Getting last TRX index, sent = 1
[15:20:30:8655415] get_last_request_trx_index: Got TRX(0) for sent req
[15:20:30:8655416] sipTransportSendMessage: ccb <6>: config <172.16.12.98>:<5060> - remote <0.0.0.0>:<5060>
[15:20:30:8655417] sipTransportSendMessage: Opened a one-time UDP send channel to server <172.16.12.98>:<5060>, handle = 8 local port= 0
[15:20:30:8655417] sipTransportSendMessage:Sent SIP message to <172.16.12.98>:<5060>, handle=<8>, length=<803>, message=
[15:20:30:8655418] REGISTER sip:172.16.12.98 SIP/2.0
Via: SIP/2.0/UDP 172.16.13.212:5061;branch=z9hG4bK0155cff0
From: <sip:21011@172.16.12.98>;tag=00119378e3d105b974018012-0e55abfc
To: <sip:21011@172.16.12.98>
Call-ID: 00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212
Max-Forwards: 70
Date: Wed, 27 Apr 2016 14:20:30 GMT
CSeq: 5835 REGISTER
User-Agent: Cisco-CP7940G/8.0
[15:20:30:8655422] SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 172.16.13.212:5061;received=172.16.13.212;branch=z9hG4bK0155cff0
Call-ID: 00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212
From: <sip:21011@172.16.12.98>;tag=00119378e3d105b974018012-0e55abfc
To: <sip:21011@172.16.12.98>;tag=z9hG4bK0155cff0
CSeq: 5835 REGISTER
WWW-Authenticate: Digest  realm="asterisk",nonce="1461766829/b4c8fd648f62b7e5d88fe99e8a8a88e3",opaque="585cacc538b92f3e",stale=true,algorithm=md5,qop="auth"
Server: Asterisk PBX certified/13.1-cert6
Content-Length:  0

[15:20:30:8655425] SIPTaskProcessSIPMessage: Line filter: Determining destination line...
[15:20:30:8655425] get_method_request_trx_index: Getting TRX for method(REGISTER), sent = 1
[15:20:30:8655426] get_method_request_trx_index: Got TRX(0) for sent method(REGISTER)
[15:20:30:8655426] sip_sm_ccb_match_branch_cseq: Matched branch_id & CSeq
[15:20:30:8655427] SIPTaskProcessSIPMessage: Line filter: Call ID match:  Destination line = <6/1>.
[15:20:30:8655427] SIPTaskProcessSIPMessage: Received SIP response.
[15:20:30:8655428] get_method_request_trx_index: Getting TRX for method(REGISTER), sent = 1
[15:20:30:8655429] get_method_request_trx_index: Got TRX(0) for sent method(REGISTER)
[15:20:30:8655429] sipSPICheckResponse: Response match: callid=00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212, cseq=5835, cseq_method=REGISTER
[15:20:30:8655430] SIPTaskProcessSIPMessage: Stopping any outstanding reTx timers...
[15:20:30:8655432] LINE 6/1: sip_sm_check_retx_timers           : Stopping reTx timer.
(callid=00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212, cseq=5835, cseq_method=REGISTER)
[15:20:30:8655433] SIPTaskProcessSIPMessage: Recv 4xx/5xx/6xx message.
[15:20:30:8655433] LINE 6/1: --0x000728dd--                     : SIP_REG_STATE_REGISTERING <- E_SIP_REG_4xx
[15:20:30:8655434] clean_method_request_trx: Removing TRX for method(REGISTER), sent = 1
[15:20:30:8655434] clean_method_request_trx: Removed TRX(0) for method(REGISTER)
[15:20:30:8655435] LINE 6/1: ccsip_handle_ev_4xx                : SIP_REG_STATE_REGISTERING <- SIP(401)
[15:20:30:8655437] SIPSPISendRegister: Sending REGISTER...
[15:20:30:8655437] get_next_request_trx_index: Getting next TRX index, sent = 1
[15:20:30:8655438] get_next_request_trx_index: Got TRX(0) for sent req
[15:20:30:8655438] get_last_request_trx_index: Getting last TRX index, sent = 1
[15:20:30:8655439] get_last_request_trx_index: Got TRX(0) for sent req
[15:20:30:8655440] get_last_request_trx_index: Getting last TRX index, sent = 1
[15:20:30:8655440] get_last_request_trx_index: Got TRX(0) for sent req
[15:20:30:8655442] get_last_request_trx_index: Getting last TRX index, sent = 1
[15:20:30:8655442] get_last_request_trx_index: Got TRX(0) for sent req
[15:20:30:8655444] sipTransportSendMessage: ccb <6>: config <172.16.12.98>:<5060> - remote <0.0.0.0>:<5060>
[15:20:30:8655445] sipTransportSendMessage: Opened a one-time UDP send channel to server <172.16.12.98>:<5060>, handle = 8 local port= 0
[15:20:30:8655445] sipTransportSendMessage:Sent SIP message to <172.16.12.98>:<5060>, handle=<8>, length=<803>, message=
[15:20:30:8655446] REGISTER sip:172.16.12.98 SIP/2.0
Via: SIP/2.0/UDP 172.16.13.212:5061;branch=z9hG4bK074e6361
From: <sip:21011@172.16.12.98>;tag=00119378e3d105b974018012-0e55abfc
To: <sip:21011@172.16.12.98>
Call-ID: 00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212
Max-Forwards: 70
Date: Wed, 27 Apr 2016 14:20:30 GMT
CSeq: 5836 REGISTER
User-Agent: Cisco-CP7940G/8.0
Contact: <sip:21011@172.16.13.212:5061;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-00119378e3d1>";+u.sip!model.ccm.cisco.com="8"
Authorization: Digest username="21011",realm="asterisk",uri="sip:172.16.12.98",response="84b7f03ef81b2cb540c7aa13d43b8e26",nonce="1461766829/b4c8fd648f62b7e5d88fe99e8a8a88e3",opaque="585cacc538b92f3e",cnonce="6a180cd0",qop=auth,nc=00000003,algorithm=md5
Content-Length: 0
Expires: 3600

[15:20:30:8655448] sipTransportSendMessage: Closed a one-time UDP send channel handle = 8
[15:20:30:8655448] LINE 6/1: sipTransportSendMessage            : Stopping reTx timer
[15:20:30:8655449] LINE 6/1: sipTransportSendMessage            : Starting reTx timer (500 msec)
[15:20:30:8655450] SIPTaskProcessListEvent: cmd = 0x160200
[15:20:30:8655450] SIPProcessUDPMessage: recv UDP message from <172.16.12.98>:<50195>, length=<533>, message=
[15:20:30:8655451] SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 172.16.13.212:5061;received=172.16.13.212;branch=z9hG4bK074e6361
Call-ID: 00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212
From: <sip:21011@172.16.12.98>;tag=00119378e3d105b974018012-0e55abfc
To: <sip:21011@172.16.12.98>;tag=z9hG4bK074e6361
CSeq: 5836 REGISTER
WWW-Authenticate: Digest  realm="asterisk",nonce="1461766829/b921fc8b98277d6625853999dc5ac269",opaque="4406925877f8197e",stale=true,algorithm=md5,qop="auth"
Server: Asterisk PBX certified/13.1-cert6
Content-Length:  0

[15:20:30:8655453] SIPTaskProcessSIPMessage: Line filter: Determining destination line...
[15:20:30:8655454] get_method_request_trx_index: Getting TRX for method(REGISTER), sent = 1
[15:20:30:8655454] get_method_request_trx_index: Got TRX(0) for sent method(REGISTER)
[15:20:30:8655454] sip_sm_ccb_match_branch_cseq: Matched branch_id & CSeq
[15:20:30:8655455] SIPTaskProcessSIPMessage: Line filter: Call ID match:  Destination line = <6/1>.
[15:20:30:8655455] SIPTaskProcessSIPMessage: Received SIP response.
[15:20:30:8655456] get_method_request_trx_index: Getting TRX for method(REGISTER), sent = 1
[15:20:30:8655457] get_method_request_trx_index: Got TRX(0) for sent method(REGISTER)
[15:20:30:8655457] sipSPICheckResponse: Response match: callid=00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212, cseq=5836, cseq_method=REGISTER
[15:20:30:8655458] SIPTaskProcessSIPMessage: Stopping any outstanding reTx timers...
[15:20:30:8655459] LINE 6/1: sip_sm_check_retx_timers           : Stopping reTx timer.
(callid=00119378-e3d10003-2d855642-6ebf4c9d@172.16.13.212, cseq=5836, cseq_method=REGISTER)
[15:20:30:8655461] SIPTaskProcessSIPMessage: Recv 4xx/5xx/6xx message.
[15:20:30:8655461] LINE 6/1: --0x000728dd--                     : SIP_REG_STATE_REGISTERING <- E_SIP_REG_4xx
[15:20:30:8655462] clean_method_request_trx: Removing TRX for method(REGISTER), sent = 1
[15:20:30:8655462] clean_method_request_trx: Removed TRX(0) for method(REGISTER)
[15:20:30:8655463] LINE 6/1: ccsip_handle_ev_4xx                : SIP_REG_STATE_REGISTERING <- SIP(401)
[15:20:30:8655463] LINE 6/1: no more credentials, retry 3, 3
[15:20:30:8655464] LINE 6/1: ccsip_register_cleanup             : Starting expires timer (60 sec)
[15:20:30:8655464] LINE 6/1: Registration state change: SIP_REG_STATE_REGISTERING ---> SIP_REG_STATE_IDLE
[15:20:30:8655465] LINE 6/1: sip_sm_call_cleanup                : Cleaning up the call
[15:20:30:8655465] %E620 REG auth failed: no more credentials

astbox · April 27, 2016, 6:13pm

The 172.16.13.212 is the asterisk server? You try to register in the 5061 port. I think this port is being used for the extensions that use the sip channel and not pjsip. If you want to use the pjsip you should register at the 5060. Please check your asterisk configuration, just to be sure.

felimwhiteley · April 27, 2016, 6:32pm

Hi astbox, I realise that might not have been clear from the debug:

Asterisk: 172.16.12.98
Phone: 172.16.13.212

and it is using port 5060.

felimwhiteley · May 24, 2016, 11:34am

Well I fixed it myself so putting this here to save some other sorry soul. The phones are on the same subnet as the Asterisk sever, despite this there are 2 NAT options that need to be active in order for the phone to work. In the phone SIPDefault.cnf file in the TFTP server make sure the following values are set:

NAT/Firewall Traversal

nat_enable: "1"
nat_address: ""
voip_control_port: "5061"
start_media_port: "16384"
end_media_port: "32766"
nat_received_processing: “1”

The important ones being nat_enable & nat_received_processing. Kudos should go to the authors of this page http://www.8layer8.com/?p=788

A long time digging for this I hope no one has to go through that! You then don’t need the identify settings to match to IP as you would hope.

fabioelia · December 28, 2017, 6:06pm

If you are still having trouble like I was at this point try chopping the password in half
The auto generated passwords maybe too long for the Cisco phones ( I haven’t found any documented limit )
But after cutting all the extension passwords in half from
35b1a4a70fe56c4959ca2a48b3d5bbbf to something like 35b1a4a70fe56c49

I was able to successfully get the phones registered

Topic		Replies	Views
PJSIP and Cisco 79XX phones not registering Asterisk Support	4	770	May 19, 2015
Cisco 7942G - PJSIP (Not Registering) Asterisk SIP	11	1197	March 3, 2023
Cisco 7906 Registration Asterisk Support	4	496	July 14, 2014
Cisco 7960G can't register except for one who is registered successuflly Asterisk SIP	18	622	January 11, 2021
SIP/2.0 401 Unathorized Asterisk Support	3	410	October 18, 2010

[SOLVED] Cisco 7940 401 Authorisation Failure PJSIP & Asterisk 13

NAT/Firewall Traversal

Related topics