After asterisk upgrade from 13.18 to 13.19, polycom phones not working

hi, i am using FreePBX 14.0.1.36 with asterisk 13.19.1 with pjsip endpoints. over the weekend, i applied all distro and freepbx module updates. after restarting the pbx…this included an upgrade for asterisk from 13.18 to 13.19, i noticed that the 3 polycom ip5000’s i have are showing unavailable in the “pjsip show contacts” list. the 90+ grandstream desk phones I have are not behaving this way and the poly’s were working fine prior. The polycom’s are using straight UDP (SIP) while my grandstream’s are TCP (SIP-TLS and SRTP). I am looking at the “pjsip set logging on” and i see the initial register fails but a followup register seems to be ok. When I try a call, the call sets up, the other party answers but no audio either direction.

I am not sure where to go from here, can someone point me in the right direction…here are some logs

Initial register:

uepbx1*CLI>
<— Received SIP request (534 bytes) from UDP:172.30.2.50:5060 —>
REGISTER sip:172.30.2.1:5060 SIP/2.0

Via: SIP/2.0/UDP 172.30.2.50;branch=z9hG4bK229b41cf2F2540

From: “Phoenix Conference Room” sip:5353@172.30.2.1;tag=5F2FA309-6B3DB3C2

To: sip:5353@172.30.2.1

CSeq: 1 REGISTER

Call-ID: 19557565-874811ce-41c6bf4b@172.30.2.50

Contact: sip:5353@172.30.2.50;methods=“INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER”

User-Agent: PolycomSoundStationIP-SSIP_5000-UA/4.1.1.0731

Accept-Language: en

Max-Forwards: 70

Expires: 120

Content-Length: 0

uepbx1*CLI>
<— Transmitting SIP response (516 bytes) to UDP:172.30.2.50:5060 —>
SIP/2.0 401 Unauthorized

Via: SIP/2.0/UDP 172.30.2.50;rport=5060;received=172.30.2.50;branch=z9hG4bK229b41cf2F2540

Call-ID: 19557565-874811ce-41c6bf4b@172.30.2.50

From: “Phoenix Conference Room” sip:5353@172.30.2.1;tag=5F2FA309-6B3DB3C2

To: sip:5353@172.30.2.1;tag=z9hG4bK229b41cf2F2540

CSeq: 1 REGISTER

WWW-Authenticate: Digest realm=“asterisk”,nonce=“1521555366/f3db9f9aedd38b761bd2e53663ab6171”,opaque=“0232a6743103aea9”,algorithm=md5,qop=“auth”

Server: FPBX-14.0.1.36(13.19.1)

Content-Length: 0

uepbx1*CLI>
<— Received SIP request (808 bytes) from UDP:172.30.2.50:5060 —>
REGISTER sip:172.30.2.1:5060 SIP/2.0

Via: SIP/2.0/UDP 172.30.2.50;branch=z9hG4bK63be8ec751E5501

From: “Phoenix Conference Room” sip:5353@172.30.2.1;tag=5F2FA309-6B3DB3C2

To: sip:5353@172.30.2.1

CSeq: 2 REGISTER

Call-ID: 19557565-874811ce-41c6bf4b@172.30.2.50

Contact: sip:5353@172.30.2.50;methods=“INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER”

User-Agent: PolycomSoundStationIP-SSIP_5000-UA/4.1.1.0731

Accept-Language: en

Authorization: Digest username=“5353”, realm=“asterisk”, nonce=“1521555366/f3db9f9aedd38b761bd2e53663ab6171”, qop=auth, cnonce=“zjueJVIz3mYQTA7”, nc=00000001, opaque=“0232a6743103aea9”, uri=“sip:172.30.2.1:5060”, response=“23b42f427c2954061632412cd23bdf4e”, algorithm=MD5

Max-Forwards: 70

Expires: 120

Content-Length: 0

uepbx1*CLI>
<— Transmitting SIP response (462 bytes) to UDP:172.30.2.50:5060 —>
SIP/2.0 200 OK

Via: SIP/2.0/UDP 172.30.2.50;rport=5060;received=172.30.2.50;branch=z9hG4bK63be8ec751E5501

Call-ID: 19557565-874811ce-41c6bf4b@172.30.2.50

From: “Phoenix Conference Room” sip:5353@172.30.2.1;tag=5F2FA309-6B3DB3C2

To: sip:5353@172.30.2.1;tag=z9hG4bK63be8ec751E5501

CSeq: 2 REGISTER

Date: Tue, 20 Mar 2018 14:16:06 GMT

Contact: sip:5353@172.30.2.50:5060;expires=119

Expires: 120

Server: FPBX-14.0.1.36(13.19.1)

Content-Length: 0

uepbx1*CLI>
<— Transmitting SIP request (420 bytes) to UDP:172.30.2.50:5060 —>
OPTIONS sip:5353@172.30.2.50:5060 SIP/2.0

Via: SIP/2.0/UDP 172.30.200.1:5060;rport;branch=z9hG4bKPj9b99e675-5889-4ac9-b537-0c8712a86138

From: sip:5353@172.30.2.1;tag=60a1ff0f-3548-4fdc-9e0d-5cc7b3807706

To: sip:5353@172.30.2.50

Contact: sip:5353@172.30.200.1:5060

Call-ID: 056dd420-0497-40a2-bf14-d882a61ae6ac

CSeq: 24538 OPTIONS

Max-Forwards: 70

User-Agent: FPBX-14.0.1.36(13.19.1)

Content-Length: 0

<— Transmitting SIP request (630 bytes) to UDP:172.30.2.50:5060 —>
NOTIFY sip:5353@172.30.2.50:5060 SIP/2.0

Via: SIP/2.0/UDP 172.30.200.1:5060;rport;branch=z9hG4bKPje47c0a10-b8f9-4ea2-ad6a-f34f9aba58df

From: sip:5353@172.30.2.1;tag=2995f3df-9e99-4e02-8277-5ec46a0d7903

To: sip:5353@172.30.2.50

Contact: sip:5353@172.30.200.1:5060

Call-ID: 650d92e5-1d92-46ce-ba16-05ae2a1a2e62

CSeq: 3416 NOTIFY

Subscription-State: terminated

Event: message-summary

Allow-Events: presence, dialog, message-summary, refer

Max-Forwards: 70

User-Agent: FPBX-14.0.1.36(13.19.1)

Content-Type: application/simple-message-summary

Content-Length: 48

Messages-Waiting: no

Voice-Message: 0/0 (0/0)

call attempt:

uepbx1*CLI>
<— Received SIP request (932 bytes) from UDP:172.30.2.50:5060 —>
INVITE sip:5332@172.30.2.1:5060;user=phone SIP/2.0

Via: SIP/2.0/UDP 172.30.2.50;branch=z9hG4bK38dbdea3A50E2024

From: “Phoenix Conference Room” sip:5353@172.30.2.1;tag=B1AC897D-7F5544C6

To: sip:5332@172.30.2.1;user=phone

CSeq: 1 INVITE

Call-ID: 3471c599-6e849792-2e8157df@172.30.2.50

Contact: sip:5353@172.30.2.50

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

User-Agent: PolycomSoundStationIP-SSIP_5000-UA/4.1.1.0731

Accept-Language: en

Supported: 100rel,replaces

Allow-Events: conference,talk,hold

Max-Forwards: 70

Content-Type: application/sdp

Content-Length: 292

v=0

o=- 1521555777 1521555777 IN IP4 172.30.2.50

s=Polycom IP Phone

c=IN IP4 172.30.2.50

t=0 0

a=sendrecv

m=audio 2226 RTP/AVP 0 8 18 9 127

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:9 G722/8000

a=rtpmap:127 telephone-event/8000

uepbx1*CLI>
<— Transmitting SIP response (529 bytes) to UDP:172.30.2.50:5060 —>
SIP/2.0 401 Unauthorized

Via: SIP/2.0/UDP 172.30.2.50;rport=5060;received=172.30.2.50;branch=z9hG4bK38dbdea3A50E2024

Call-ID: 3471c599-6e849792-2e8157df@172.30.2.50

From: “Phoenix Conference Room” sip:5353@172.30.2.1;tag=B1AC897D-7F5544C6

To: sip:5332@172.30.2.1;user=phone;tag=z9hG4bK38dbdea3A50E2024

CSeq: 1 INVITE

WWW-Authenticate: Digest realm=“asterisk”,nonce=“1521555778/1ce06a0e0a2c9043755bbc61ae1055ae”,opaque=“3b34662d7d8eeab1”,algorithm=md5,qop=“auth”

Server: FPBX-14.0.1.36(13.19.1)

Content-Length: 0

uepbx1*CLI>
<— Received SIP request (565 bytes) from UDP:172.30.2.50:5060 —>
ACK sip:5332@172.30.2.1:5060;user=phone SIP/2.0

Via: SIP/2.0/UDP 172.30.2.50;branch=z9hG4bK38dbdea3A50E2024

From: “Phoenix Conference Room” sip:5353@172.30.2.1;tag=B1AC897D-7F5544C6

To: sip:5332@172.30.2.1;user=phone;tag=z9hG4bK38dbdea3A50E2024

CSeq: 1 ACK

Call-ID: 3471c599-6e849792-2e8157df@172.30.2.50

Contact: sip:5353@172.30.2.50

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

User-Agent: PolycomSoundStationIP-SSIP_5000-UA/4.1.1.0731

Accept-Language: en

Max-Forwards: 70

Content-Length: 0

uepbx1*CLI>
<— Received SIP request (1221 bytes) from UDP:172.30.2.50:5060 —>
INVITE sip:5332@172.30.2.1:5060;user=phone SIP/2.0

Via: SIP/2.0/UDP 172.30.2.50;branch=z9hG4bK8b279290C67BA2F5

From: “Phoenix Conference Room” sip:5353@172.30.2.1;tag=B1AC897D-7F5544C6

To: sip:5332@172.30.2.1;user=phone

CSeq: 2 INVITE

Call-ID: 3471c599-6e849792-2e8157df@172.30.2.50

Contact: sip:5353@172.30.2.50

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

User-Agent: PolycomSoundStationIP-SSIP_5000-UA/4.1.1.0731

Accept-Language: en

Supported: 100rel,replaces

Allow-Events: conference,talk,hold

Authorization: Digest username=“5353”, realm=“asterisk”, nonce=“1521555778/1ce06a0e0a2c9043755bbc61ae1055ae”, qop=auth, cnonce=“fSD1YRHONCYBdFo”, nc=00000001, opaque=“3b34662d7d8eeab1”, uri=“sip:5332@172.30.2.1:5060;user=phone”, response=“30c996998c2ffe50709ef86e8c6e44fd”, algorithm=MD5

Max-Forwards: 70

Content-Type: application/sdp

Content-Length: 292

v=0

o=- 1521555777 1521555777 IN IP4 172.30.2.50

s=Polycom IP Phone

c=IN IP4 172.30.2.50

t=0 0

a=sendrecv

m=audio 2226 RTP/AVP 0 8 18 9 127

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:9 G722/8000

a=rtpmap:127 telephone-event/8000

uepbx1*CLI>
<— Transmitting SIP response (348 bytes) to UDP:172.30.2.50:5060 —>
SIP/2.0 100 Trying

Via: SIP/2.0/UDP 172.30.2.50;rport=5060;received=172.30.2.50;branch=z9hG4bK8b279290C67BA2F5

Call-ID: 3471c599-6e849792-2e8157df@172.30.2.50

From: “Phoenix Conference Room” sip:5353@172.30.2.1;tag=B1AC897D-7F5544C6

To: sip:5332@172.30.2.1;user=phone

CSeq: 2 INVITE

Server: FPBX-14.0.1.36(13.19.1)

Content-Length: 0

Check the output of “rtp set debug on” and see if the traffic is being received and is being sent to the correct IP address.

Also, that’s how REGISTER works. REGISTER w/ no auth. 401. REGISTER w/ auth. 200 OK. That’s all normal.

1 Like

jcolp, malcolmd, thanks for responding quickly! in an effort to resolve this, i tried deleting one of the affected extension and recreating it. now, that extension does not authenticate at all. is there a way to debug specifically what about the config is preventing the authentication…ie, password, id etc?

thanks>

<— Received SIP request (809 bytes) from UDP:172.30.2.50:5060 —>
REGISTER sip:172.30.2.1:5060 SIP/2.0
Via: SIP/2.0/UDP 172.30.2.50;branch=z9hG4bKb5b81ce07FEECF69
From: “Phoenix Conference Room” sip:5353@172.30.2.1;tag=D331BA51-9569C89E
To: sip:5353@172.30.2.1
CSeq: 2 REGISTER
Call-ID: 9349253d-fc83673a-4be7df2b@172.30.2.50
Contact: sip:5353@172.30.2.50;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER"
User-Agent: PolycomSoundStationIP-SSIP_5000-UA/4.1.1.0731
Accept-Language: en
Authorization: Digest username=“5353”, realm=“asterisk”, nonce=“1521566998/353bfb3cd0486ef8ac86939724e88137”, qop=auth, cnonce=“FqWuKRiGpiu9H/R”, nc=00000001, opaque=“379408c52796067b”, uri=“sip:172.30.2.1:5060”, response=“30b260910713a8753bbdcd3427cbf0ce”, algorithm=MD5
Max-Forwards: 70
Expires: 120
Content-Length: 0

[2018-03-20 13:29:58] NOTICE[27359]: res_pjsip/pjsip_distributor.c:649 log_failed_request: Request ‘REGISTER’ from ‘“Phoenix Conference Room” sip:5353@172.30.2.1’ failed for ‘172.30.2.50:5060’ (callid: 9349253d-fc83673a-4be7df2b@172.30.2.50) - Failed to authenticate
<— Transmitting SIP response (520 bytes) to UDP:172.30.2.50:5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 172.30.2.50;rport=5060;received=172.30.2.50;branch=z9hG4bKb5b81ce07FEECF69
Call-ID: 9349253d-fc83673a-4be7df2b@172.30.2.50
From: “Phoenix Conference Room” sip:5353@172.30.2.1;tag=D331BA51-9569C89E
To: sip:5353@172.30.2.1;tag=z9hG4bKb5b81ce07FEECF69
CSeq: 2 REGISTER
WWW-Authenticate: Digest realm=“asterisk”,nonce=“1521566998/353bfb3cd0486ef8ac86939724e88137”,opaque=“622c80887b41b88e”,algorithm=md5,qop="auth"
Server: FPBX-14.0.1.36(13.19.1)
Content-Length: 0

You would need to check the configuration itself and the configuration on the device. The message is usually the result of an incorrect password.

403 would be an incorrect password. If this log is complete, it means that the phone doesn’t have a password at all, so is getting stuck when asked for one.

it hard to say for sure, but i have checked the pjsip config file with the config file the phone is downloading…the passwords are the same. i am looking at a packet capture now, and i don’t see where the password is in the packet…is it md5 hashed ?

Yes, it is md5 hashed using different components. I don’t have it handy, but it is documented online. It is not communicated in clear text as it would be easy for someone to get credentials.