PJSIP subscriptions broken after upgrade Asterisk 13.4

After upgrade from Asterisk 13.2 to 13.4, the PJSIP subscriptions for “buddies” stop to works with our devices Polycom. We use the simple “presence” fonction on this device. Collegues can see who is on the phone by looking their “buddies”. It was working well before with version 13.2. For exemple here what I see in the log for one subscription “4125”:

core show hints:
4125@ext-local : PJSIP/4125&Custom:DN State:Idle Presence: Watchers 0

[code][2015-07-30 05:38:58] VERBOSE[1769] res_pjsip_logger.c: <— Received SIP request (920 bytes) from UDP:192.16.100.242:5060 —>
SUBSCRIBE sip:4125@192.16.100.6:5060 SIP/2.0
Via: SIP/2.0/UDP 192.16.100.242:5060;branch=z9hG4bK1f33bb0dA8791608
From: “Polycom550” sip:4127@192.16.100.6;tag=1057088E-46601B3D
To: sip:4125@192.16.100.6
CSeq: 2 SUBSCRIBE
Call-ID: 475cfe64-c008918b-2a97cb1e@192.16.100.242
Contact: sip:4127@192.16.100.242:5060
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
Event: presence
User-Agent: PolycomSoundPointIP-SPIP_550-UA/3.3.5.0247
Accept-Language: fr-fr,fr;q=0.9,en;q=0.8
Accept: application/xpidf+xml,text/xml+msrtc.pidf
Authorization: Digest username=“4127”, realm=“asterisk”, nonce=“1438249138/1af953383e9e23ee071039d05b76003b”, qop=auth, cnonce="tOoSd+yq61wb$
Max-Forwards: 70
Expires: 3600
Content-Length: 0

[2015-07-30 05:38:58] DEBUG[1764] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against
[2015-07-30 05:38:58] DEBUG[1764] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 4127
[2015-07-30 05:38:58] DEBUG[1764] res_pjsip_nat.c: Re-wrote Contact URI host/port to 192.16.100.242:5060
[2015-07-30 05:38:58] DEBUG[1764] res_pjsip_authenticator_digest.c: Calculated nonce 1438249138/1af953383e9e23ee071039d05b76003b. Actual non$
[2015-07-30 05:38:58] DEBUG[1764] res_pjsip_pubsub.c: Body generator 0x7f9dc25304e0 found for accept type application/xpidf+xml
[2015-07-30 05:38:58] DEBUG[1764] res_pjsip_pubsub.c: Subscription to resource 4125 is not to a list
[2015-07-30 05:38:58] DEBUG[1764] config.c: extract int from [0] in [-2147483648, 2147483647] gives 0
[2015-07-30 05:38:58] DEBUG[1764] config.c: extract int from [0] in [-2147483648, 2147483647] gives 0
[2015-07-30 05:38:58] DEBUG[1764] config.c: extract int from [0] in [-2147483648, 2147483647] gives 0
[2015-07-30 05:38:58] DEBUG[1764] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 192.16.100.6:5060
[2015-07-30 05:38:58] VERBOSE[1764] res_pjsip_logger.c: <— Transmitting SIP response (583 bytes) to UDP:192.16.100.242:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.16.100.242:5060;rport=5060;received=192.16.100.242;branch=z9hG4bK1f33bb0dA8791608
Call-ID: 475cfe64-c008918b-2a97cb1e@192.16.100.242
From: “Polycom550” sip:4127@192.16.100.6;tag=1057088E-46601B3D
To: sip:4125@192.16.100.6;tag=TUXZ8VPVvS9AFpjvcIS0X6ukgiUMrVXO
CSeq: 2 SUBSCRIBE
Expires: 3600
Contact: sip:192.16.100.6:5060
Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, MESSAGE, REFER
Supported: 100rel, timer, replaces, norefersub
Server: FPBX-12.0.74(13.4.0)
Content-Length: 0

[2015-07-30 05:38:58] DEBUG[1764] db.c: Unable to find key ‘4125’ in family ‘CustomPresence’
[2015-07-30 05:38:58] DEBUG[1764] pjsip: evsub0x7f9de40 .Subscription state changed NULL --> TERMINATED
[2015-07-30 05:38:58] DEBUG[1764] res_pjsip_pubsub.c: Removing subscription to resource 4125 from list of subscriptions
[2015-07-30 05:38:58] DEBUG[1764] res_pjsip_pubsub.c: Destroying SIP subscription to resource 4125[/code]

I wonder what means the three last entries. Everything seems OK but at the end something happens and the subscriptions is destroyed. I test it on a fresh new install (FreePBX distro 6.12.65).

Thanks!

Ok I’ve found something that seems to fix this but I’m not sure of the long term consequence.

At the subscription time, the device send “SUBSCRIBE” to the hint to watch the presence state. But the “presence” value for this hint is NULL by default and it doesn’t create the “watchers” for this reason. I think the presence value should show “not_set” instead of just NULL or empty. That is my guess…

The trick I’v found is to create a CustomPresence not null. So before the “Presence” is empty for the hint (not “not_set” like the others entries, but just empty):
“core show hints”:
4125@ext-local : PJSIP/4125&Custom:DN State:Idle [color=#FF0000]Presence:[/color] Watchers 0
4127@ext-local : PJSIP/4127&Custom:DN State:Idle Presence: Watchers 0
*85@park-hints : park:71@parkedcalls& State:Unavailable [color=#FF0000]Presence:not_set[/color] Watchers 0

I’ve set a new CustomPresence for the extension hint “4125” with this command: “presencestate change CustomPresence:4125 available”. After restarting the phone now the “SUBSCRIBE” works for this extension hint:
4125@ext-local : PJSIP/4125&Custom:DN State:Idle [color=#FF0000]Presence:available Watchers 1[/color]
4127@ext-local : PJSIP/4127&Custom:DN State:Idle Presence: Watchers 0
*85@park-hints : park:71@parkedcalls& State:Unavailable Presence:not_set Watchers 0

I see now one watchers and the phone can see the state of this “buddy”. What we want is simply watching the “EXTENSION_STATE” not “PRESENCE_STATE” introduce in Asterisk 11. The presence state in Asterisk 13.3 or 13.4 seems to have broke the subscription, that is my hypothesis so far.

I see the bug ASTERISK-25202 (https://issues.asterisk.org/jira/browse/ASTERISK-25202) that seems maybe related but that is not exactly my problem. Someone may confirm the issue I’m facing will be fix in version 13.5 or it is a new one?

Howdy,

Changelog for 13.5-rc1 [1] shows the fix for ASTERISK-25202.

Cheers

1 - downloads.asterisk.org/pub/telep … 13.5.0-rc1

Seems to me the real issue is this: issues.asterisk.org/jira/browse/ASTERISK-25400

Not the one that was linked to previously