Station to Station calls failing (nonce problem)

General Help
1

FreePbx Distro
FreePBX 13.0.70
Asterisk 13.7.0

Hi, Hopefully, this is something simple. I have two Cisco 7940’s connected using PJSIP. I (as others have) battled to get these phones registered but finally got it figured out. The key is, the phone need 8 character passwords and under advanced, you need to set “Force rport” to no.

If I do a “pjsip show endpoints”, i see both phones registered. If I try to call between them, I get a fast busy. So I figure, it must be still something with the phones.

I installed a softphone on my desktop, added an extension, logged in and dialed one of the Cisco’s – call went right through.

Called the other phone – no problem.

Tried calling the softphone from a Cisco – no dice.

I tried comparing the logs from a “good” call and a bad call. On the bad call, it looks like the “nonce” compare fails. Log is attached below.

Any ideas? Thanks. – Bud

freepbx*CLI> 
<--- Received SIP request (951 bytes) from UDP:192.168.160.105:51623 --->
INVITE sip:[email protected];user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.160.105:5060;branch=z9hG4bK117dd108
From: "125" <sip:[email protected]>;tag=001f9e244f8d01f546f904f8-132cb712
To: <sip:[email protected];user=phone>
Call-ID: [email protected]
Max-Forwards: 70
CSeq: 101 INVITE
User-Agent: Cisco-CP7940G/8.0
Contact: <sip:[email protected]:5060;user=phone;transport=udp>
Expires: 180
Accept: application/sdp
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE
Supported: replaces,join,norefersub
Content-Length: 282
Content-Type: application/sdp
Content-Disposition: session;handling=optional

v=0
o=Cisco-SIPUA 28439 0 IN IP4 192.168.160.105
s=SIP Call
t=0 0
m=audio 17262 RTP/AVP 0 8 18 101
c=IN IP4 192.168.160.105
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv

[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:113 ip_identify_match_check: Source address 192.168.160.105:51623 does not match identify 'voip.ms'
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:137 ip_identify: '192.168.160.105:51623' did not match any identify section rules
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_user.c:104 username_identify: Retrieved endpoint 125
<--- Transmitting SIP response (529 bytes) to UDP:192.168.160.105:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.160.105:5060;received=192.168.160.105;branch=z9hG4bK117dd108
Call-ID: [email protected]
From: "125" <sip:[email protected]>;tag=001f9e244f8d01f546f904f8-132cb712
To: <sip:[email protected];user=phone>;tag=z9hG4bK117dd108
CSeq: 101 INVITE
WWW-Authenticate: Digest  realm="asterisk",nonce="1456431726/90a13746844faab253296e8a2b1db260",opaque="4ae8a30840ab9385",algorithm=md5,qop="auth"
Server: FPBX-13.0.70(13.7.0)
Content-Length:  0


<--- Received SIP request (344 bytes) from UDP:192.168.160.105:51624 --->
ACK sip:[email protected];user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.160.105:5060;branch=z9hG4bK117dd108
From: "125" <sip:[email protected]>;tag=001f9e244f8d01f546f904f8-132cb712
To: <sip:[email protected];user=phone>;tag=z9hG4bK117dd108
Call-ID: [email protected]
CSeq: 101 ACK
Content-Length: 0


[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:113 ip_identify_match_check: Source address 192.168.160.105:51624 does not match identify 'voip.ms'
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:137 ip_identify: '192.168.160.105:51624' did not match any identify section rules
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_user.c:104 username_identify: Retrieved endpoint 125
<--- Received SIP request (1221 bytes) from UDP:192.168.160.105:51625 --->
INVITE sip:[email protected];user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.160.105:5060;branch=z9hG4bK495971fe
From: "125" <sip:[email protected]>;tag=001f9e244f8d01f546f904f8-132cb712
To: <sip:[email protected];user=phone>
Call-ID: [email protected]
Max-Forwards: 70
CSeq: 102 INVITE
User-Agent: Cisco-CP7940G/8.0
Contact: <sip:[email protected]:5060;user=phone;transport=udp>
Authorization: Digest username="125",realm="asterisk",uri="sip:[email protected];user=phone",response="ec93b2307db7e4d55b3b0aa8fd9d3fd7",nonce="1456431726/90a13746844faab253296e8a2b1db260",opaque="4ae8a30840ab9385",cnonce="2b4148cb",qop=auth,nc=00000001,algorithm=md5
Expires: 180
Accept: application/sdp
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE
Supported: replaces,join,norefersub
Content-Length: 282
Content-Type: application/sdp
Content-Disposition: session;handling=optional

v=0
o=Cisco-SIPUA 28439 0 IN IP4 192.168.160.105
s=SIP Call
t=0 0
m=audio 17262 RTP/AVP 0 8 18 101
c=IN IP4 192.168.160.105
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv

[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:113 ip_identify_match_check: Source address 192.168.160.105:51625 does not match identify 'voip.ms'
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:137 ip_identify: '192.168.160.105:51625' did not match any identify section rules
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_user.c:104 username_identify: Retrieved endpoint 125
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_authenticator_digest.c:250 check_nonce: Calculated nonce 1456431726/fbe634ad8e5f10081ce50442a567617a. Actual nonce is 1456431726/90a13746844faab253296e8a2b1db260
<--- Transmitting SIP response (540 bytes) to UDP:192.168.160.105:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.160.105:5060;received=192.168.160.105;branch=z9hG4bK495971fe
Call-ID: [email protected]
From: "125" <sip:[email protected]>;tag=001f9e244f8d01f546f904f8-132cb712
To: <sip:[email protected];user=phone>;tag=z9hG4bK495971fe
CSeq: 102 INVITE
WWW-Authenticate: Digest  realm="asterisk",nonce="1456431726/fbe634ad8e5f10081ce50442a567617a",opaque="6422724646c3ecbb",stale=true,algorithm=md5,qop="auth"
Server: FPBX-13.0.70(13.7.0)
Content-Length:  0


<--- Received SIP request (344 bytes) from UDP:192.168.160.105:51626 --->
ACK sip:[email protected];user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.160.105:5060;branch=z9hG4bK495971fe
From: "125" <sip:[email protected]>;tag=001f9e244f8d01f546f904f8-132cb712
To: <sip:[email protected];user=phone>;tag=z9hG4bK495971fe
Call-ID: [email protected]
CSeq: 102 ACK
Content-Length: 0


[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:113 ip_identify_match_check: Source address 192.168.160.105:51626 does not match identify 'voip.ms'
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:137 ip_identify: '192.168.160.105:51626' did not match any identify section rules
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_user.c:104 username_identify: Retrieved endpoint 125
<--- Received SIP request (1221 bytes) from UDP:192.168.160.105:51627 --->
INVITE sip:[email protected];user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.160.105:5060;branch=z9hG4bK0faf7afd
From: "125" <sip:[email protected]>;tag=001f9e244f8d01f546f904f8-132cb712
To: <sip:[email protected];user=phone>
Call-ID: [email protected]
Max-Forwards: 70
CSeq: 103 INVITE
User-Agent: Cisco-CP7940G/8.0
Contact: <sip:[email protected]:5060;user=phone;transport=udp>
Authorization: Digest username="125",realm="asterisk",uri="sip:[email protected];user=phone",response="68499d1e03bff3f70efcb4df7d94a25d",nonce="1456431726/fbe634ad8e5f10081ce50442a567617a",opaque="6422724646c3ecbb",cnonce="025172ba",qop=auth,nc=00000001,algorithm=md5
Expires: 180
Accept: application/sdp
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE
Supported: replaces,join,norefersub
Content-Length: 282
Content-Type: application/sdp
Content-Disposition: session;handling=optional

v=0
o=Cisco-SIPUA 28439 0 IN IP4 192.168.160.105
s=SIP Call
t=0 0
m=audio 17262 RTP/AVP 0 8 18 101
c=IN IP4 192.168.160.105
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv

[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:113 ip_identify_match_check: Source address 192.168.160.105:51627 does not match identify 'voip.ms'
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:137 ip_identify: '192.168.160.105:51627' did not match any identify section rules
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_user.c:104 username_identify: Retrieved endpoint 125
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_authenticator_digest.c:250 check_nonce: Calculated nonce 1456431726/a55474458b258b6a7319636099e55da8. Actual nonce is 1456431726/fbe634ad8e5f10081ce50442a567617a
<--- Transmitting SIP response (540 bytes) to UDP:192.168.160.105:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.160.105:5060;received=192.168.160.105;branch=z9hG4bK0faf7afd
Call-ID: [email protected]
From: "125" <sip:[email protected]>;tag=001f9e244f8d01f546f904f8-132cb712
To: <sip:[email protected];user=phone>;tag=z9hG4bK0faf7afd
CSeq: 103 INVITE
WWW-Authenticate: Digest  realm="asterisk",nonce="1456431726/a55474458b258b6a7319636099e55da8",opaque="587e738605a6de3e",stale=true,algorithm=md5,qop="auth"
Server: FPBX-13.0.70(13.7.0)
Content-Length:  0


<--- Received SIP request (344 bytes) from UDP:192.168.160.105:51628 --->
ACK sip:[email protected];user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.160.105:5060;branch=z9hG4bK0faf7afd
From: "125" <sip:[email protected]>;tag=001f9e244f8d01f546f904f8-132cb712
To: <sip:[email protected];user=phone>;tag=z9hG4bK0faf7afd
Call-ID: [email protected]
CSeq: 103 ACK
Content-Length: 0


[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:113 ip_identify_match_check: Source address 192.168.160.105:51628 does not match identify 'voip.ms'
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:137 ip_identify: '192.168.160.105:51628' did not match any identify section rules
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_user.c:104 username_identify: Retrieved endpoint 125
<--- Received SIP request (1221 bytes) from UDP:192.168.160.105:51629 --->
INVITE sip:[email protected];user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.160.105:5060;branch=z9hG4bK18d33110
From: "125" <sip:[email protected]>;tag=001f9e244f8d01f546f904f8-132cb712
To: <sip:[email protected];user=phone>
Call-ID: [email protected]
Max-Forwards: 70
CSeq: 104 INVITE
User-Agent: Cisco-CP7940G/8.0
Contact: <sip:[email protected]:5060;user=phone;transport=udp>
Authorization: Digest username="125",realm="asterisk",uri="sip:[email protected];user=phone",response="8cf15086a12173ada99e4ff821252e5a",nonce="1456431726/a55474458b258b6a7319636099e55da8",opaque="587e738605a6de3e",cnonce="61c85696",qop=auth,nc=00000001,algorithm=md5
Expires: 180
Accept: application/sdp
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE
Supported: replaces,join,norefersub
Content-Length: 282
Content-Type: application/sdp
Content-Disposition: session;handling=optional

v=0
o=Cisco-SIPUA 28439 0 IN IP4 192.168.160.105
s=SIP Call
t=0 0
m=audio 17262 RTP/AVP 0 8 18 101
c=IN IP4 192.168.160.105
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv

[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:113 ip_identify_match_check: Source address 192.168.160.105:51629 does not match identify 'voip.ms'
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:137 ip_identify: '192.168.160.105:51629' did not match any identify section rules
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_user.c:104 username_identify: Retrieved endpoint 125
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_authenticator_digest.c:250 check_nonce: Calculated nonce 1456431726/5eafc2504205563ec55427754d4998f1. Actual nonce is 1456431726/a55474458b258b6a7319636099e55da8
<--- Transmitting SIP response (540 bytes) to UDP:192.168.160.105:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.160.105:5060;received=192.168.160.105;branch=z9hG4bK18d33110
Call-ID: [email protected]
From: "125" <sip:[email protected]>;tag=001f9e244f8d01f546f904f8-132cb712
To: <sip:[email protected];user=phone>;tag=z9hG4bK18d33110
CSeq: 104 INVITE
WWW-Authenticate: Digest  realm="asterisk",nonce="1456431726/5eafc2504205563ec55427754d4998f1",opaque="294e1f98314ed4c0",stale=true,algorithm=md5,qop="auth"
Server: FPBX-13.0.70(13.7.0)
Content-Length:  0


<--- Received SIP request (344 bytes) from UDP:192.168.160.105:51630 --->
ACK sip:[email protected];user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.160.105:5060;branch=z9hG4bK18d33110
From: "125" <sip:[email protected]>;tag=001f9e244f8d01f546f904f8-132cb712
To: <sip:[email protected];user=phone>;tag=z9hG4bK18d33110
Call-ID: [email protected]
CSeq: 104 ACK
Content-Length: 0


[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:113 ip_identify_match_check: Source address 192.168.160.105:51630 does not match identify 'voip.ms'
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_ip.c:137 ip_identify: '192.168.160.105:51630' did not match any identify section rules
[2016-02-25 14:22:06] DEBUG[2049]: res_pjsip_endpoint_identifier_user.c:104 username_identify: Retrieved endpoint 125
freepbx*CLI> 
freepbx*CLI> 
freepbx*CLI> 
freepbx*CLI>
2

Just highlighting the line that I assume is causing the issue. From the code:

Ensure that a nonce on an incoming request is sane.

The nonce in an incoming Authorization header needs to pass some scrutiny in order
for us to consider accepting it. What we do is re-build a nonce based on request
data and a realm and see if it matches the nonce they sent us.
\param candidate The nonce on an incoming request
\param rdata The incoming request
\param auth The auth credentials we are trying to match against.
\retval 0 Nonce does not pass validity checks
\retval 1 Nonce passes validity check