[asterisk-bugs] [JIRA] (ASTERISK-26696) PJSip Subscription Persistence in AstDB Does not update on subscription refresh

Thu Jan 5 12:37:10 CST 2017

     [ https://issues.asterisk.org/jira/browse/ASTERISK-26696?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Zach R updated ASTERISK-26696:
------------------------------

    Description: 
When a phone (say a Cisco SPA 504G) subscribes to a hint about another extension it properly creates the persistence information in the AstDB. But after 30 minutes or whenever the phone sends another subscribe to refresh its subscription the persistence key does not have its expiration timestamp updated to the new time.

This results in the fact subscriptions are not persistent across crashes or restarts, since it sees the subscription as expired when it goes to rebuild subscriptions from the persistence keys. So it would start with no watchers instead of however many it had before the server restarted or crashed.

For example, say extension 500 subscribes to the hint for x501 at 4 AM and has an expiration of 30 minutes. The subscription persistence token in the astdb (database show subscription_persistence) has a timestamp that says it expires at 4:30 AM. Around 4:29 x500 sends a subscribe to refresh the subscription so that it should expire at 5 AM. Yet the astdb database still shows that subscription as expiring at 4:30 AM. 

Say the Asterisk server than restarts at 4:45 AM, when x500's subscription to the hint for x501 is still valid. Once it comes back up the hint for x501 will show as 0 watchers instead of 1 as it was before the restart.

I've included an example below from a development server:

/subscription_persistence/subscription_persistence/b83309ef-e958-429a-a150-02c01327b2b1: {"local_port":"5060","endpoint":"107-eng4","src_port":"5060","transport_key":"UDP","packet":"SUBSCRIBE sip:288 at eng4.sip.monmouth.com SIP/2.0\r\nVia: SIP/2.0/UDP 64.19.186.174:5060;branch=z9hG4bK5a9203f345803ecac6c09fc88d86b8bf\r\nVia: SIP/2.0/UDP 10.0.15.188:5060;branch=z9hG4bK-9a01007c\r\nFrom: \"107 test\" <sip:107-eng4 at eng4.sip.monmouth.com>;tag=dbf1bb778d0a69c1\r\nTo: <sip:288 at eng4.sip.monmouth.com>\r\nCall-ID: 96752e2f-e962d669 at 10.0.15.188\r\nCSeq: 26153 SUBSCRIBE\r\nContact: \"107 test\" <sip:107-eng4 at 64.19.186.174>\r\nAuthorization: Digest username=\"107-eng4\", realm=\"asterisk\", nonce=\"1483464068/53bc0175eb9b908d6651b2792c4250a8\", uri=\"sip:288 at eng4.sip.monmouth.com\", response=\"07a7013bef2c6312a810d3de45900e51\", algorithm=MD5, cnonce=\"86b9bb98\", opaque=\"0428c5a113a17b58\", qop=auth, nc=00000001\r\nAccept: application/dialog-info+xml\r\nMax-forwards: 69\r\nExpires: 1800\r\nEvent: dialog\r\nUser-agent: foobar\r\nContent-Length: 0\r\n\r","expires":"1483465868","src_name":"64.19.186.174","cseq":"2924","local_name":"209.191.9.28","tag":"07c6bd3d-37db-4031-b82b-92572eccbf0a"}

The expires timestamp shows it should expire at 2017-01-03 12:51:08 -0500 and throughout the day this timestamp didn't change even though the phone never got unplugged or restarted. The subscription was still valid as well since it showed a watcher for extension 288 throughout the day (and was tested on the phone as well to confirm the blf updated properly based on the state of x288). When I restarted the server this key from the astdb got removed, and the watchers for 288 was at 0 until the extension 107 that was watching 288 sent another subscribe.

  was:
When a phone (say a Cisco SPA 504G) subscribes to a hint about another extension it properly creates the persistence information in the AstDB. But after 30 minutes or whenever the phone sends another subscribe to refresh its subscription the persistence key does not have its expiration timestamp updated to the new time.

This results in the fact subscriptions are not persistent across crashes or restarts, since it sees the subscription as expired when it goes to rebuild subscriptions from the persistence keys. So it would start with no watchers instead of however many it had before the server restarted or crashed.

For example, say extension 500 subscribes to the hint for x501 at 4 AM and has an expiration of 30 minutes. The subscription persistence token in the astdb (database show subscription_persistence) has a timestamp that says it expires at 4:30 AM. Around 4:29 x500 sends a subscribe to refresh the subscription so that it should expire at 5 AM. Yet the astdb database still shows that subscription as expiring at 4:30 AM. 

Say the Asterisk server than restarts at 4:45 AM, when x500's subscription to the hint for x501 is still valid. Once it comes back up the hint for x501 will show as 0 watchers instead of 1 as it was before the restart.

I've included an example below:

/subscription_persistence/subscription_persistence/b83309ef-e958-429a-a150-02c01327b2b1: {"local_port":"5060","endpoint":"107-eng4","src_port":"5060","transport_key":"UDP","packet":"SUBSCRIBE sip:288 at eng4.sip.monmouth.com SIP/2.0\r\nVia: SIP/2.0/UDP 64.19.186.174:5060;branch=z9hG4bK5a9203f345803ecac6c09fc88d86b8bf\r\nVia: SIP/2.0/UDP 10.0.15.188:5060;branch=z9hG4bK-9a01007c\r\nFrom: \"107 test\" <sip:107-eng4 at eng4.sip.monmouth.com>;tag=dbf1bb778d0a69c1\r\nTo: <sip:288 at eng4.sip.monmouth.com>\r\nCall-ID: 96752e2f-e962d669 at 10.0.15.188\r\nCSeq: 26153 SUBSCRIBE\r\nContact: \"107 test\" <sip:107-eng4 at 64.19.186.174>\r\nAuthorization: Digest username=\"107-eng4\", realm=\"asterisk\", nonce=\"1483464068/53bc0175eb9b908d6651b2792c4250a8\", uri=\"sip:288 at eng4.sip.monmouth.com\", response=\"07a7013bef2c6312a810d3de45900e51\", algorithm=MD5, cnonce=\"86b9bb98\", opaque=\"0428c5a113a17b58\", qop=auth, nc=00000001\r\nAccept: application/dialog-info+xml\r\nMax-forwards: 69\r\nExpires: 1800\r\nEvent: dialog\r\nUser-agent: foobar\r\nContent-Length: 0\r\n\r","expires":"1483465868","src_name":"64.19.186.174","cseq":"2924","local_name":"209.191.9.28","tag":"07c6bd3d-37db-4031-b82b-92572eccbf0a"}

The expires timestamp shows it should expire at 2017-01-03 12:51:08 -0500 and throughout the day this timestamp didn't change even though the phone never got unplugged or restarted. The subscription was still valid as well since it showed a watcher for extension 288 throughout the day (and was tested on the phone as well to confirm the blf updated properly based on the state of x288). When I restarted the server this key from the astdb got removed, and the watchers for 288 was at 0 until the extension 107 that was watching 288 sent another subscribe.

> PJSip Subscription Persistence in AstDB Does not update on subscription refresh
> -------------------------------------------------------------------------------
>
>                 Key: ASTERISK-26696
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-26696
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: pjproject/pjsip
>    Affects Versions: 13.0.0
>         Environment: CentOS 6.6 Final
>            Reporter: Zach R
>            Severity: Minor
>
> When a phone (say a Cisco SPA 504G) subscribes to a hint about another extension it properly creates the persistence information in the AstDB. But after 30 minutes or whenever the phone sends another subscribe to refresh its subscription the persistence key does not have its expiration timestamp updated to the new time.
> This results in the fact subscriptions are not persistent across crashes or restarts, since it sees the subscription as expired when it goes to rebuild subscriptions from the persistence keys. So it would start with no watchers instead of however many it had before the server restarted or crashed.
> For example, say extension 500 subscribes to the hint for x501 at 4 AM and has an expiration of 30 minutes. The subscription persistence token in the astdb (database show subscription_persistence) has a timestamp that says it expires at 4:30 AM. Around 4:29 x500 sends a subscribe to refresh the subscription so that it should expire at 5 AM. Yet the astdb database still shows that subscription as expiring at 4:30 AM. 
> Say the Asterisk server than restarts at 4:45 AM, when x500's subscription to the hint for x501 is still valid. Once it comes back up the hint for x501 will show as 0 watchers instead of 1 as it was before the restart.
> I've included an example below from a development server:
> /subscription_persistence/subscription_persistence/b83309ef-e958-429a-a150-02c01327b2b1: {"local_port":"5060","endpoint":"107-eng4","src_port":"5060","transport_key":"UDP","packet":"SUBSCRIBE sip:288 at eng4.sip.monmouth.com SIP/2.0\r\nVia: SIP/2.0/UDP 64.19.186.174:5060;branch=z9hG4bK5a9203f345803ecac6c09fc88d86b8bf\r\nVia: SIP/2.0/UDP 10.0.15.188:5060;branch=z9hG4bK-9a01007c\r\nFrom: \"107 test\" <sip:107-eng4 at eng4.sip.monmouth.com>;tag=dbf1bb778d0a69c1\r\nTo: <sip:288 at eng4.sip.monmouth.com>\r\nCall-ID: 96752e2f-e962d669 at 10.0.15.188\r\nCSeq: 26153 SUBSCRIBE\r\nContact: \"107 test\" <sip:107-eng4 at 64.19.186.174>\r\nAuthorization: Digest username=\"107-eng4\", realm=\"asterisk\", nonce=\"1483464068/53bc0175eb9b908d6651b2792c4250a8\", uri=\"sip:288 at eng4.sip.monmouth.com\", response=\"07a7013bef2c6312a810d3de45900e51\", algorithm=MD5, cnonce=\"86b9bb98\", opaque=\"0428c5a113a17b58\", qop=auth, nc=00000001\r\nAccept: application/dialog-info+xml\r\nMax-forwards: 69\r\nExpires: 1800\r\nEvent: dialog\r\nUser-agent: foobar\r\nContent-Length: 0\r\n\r","expires":"1483465868","src_name":"64.19.186.174","cseq":"2924","local_name":"209.191.9.28","tag":"07c6bd3d-37db-4031-b82b-92572eccbf0a"}
> The expires timestamp shows it should expire at 2017-01-03 12:51:08 -0500 and throughout the day this timestamp didn't change even though the phone never got unplugged or restarted. The subscription was still valid as well since it showed a watcher for extension 288 throughout the day (and was tested on the phone as well to confirm the blf updated properly based on the state of x288). When I restarted the server this key from the astdb got removed, and the watchers for 288 was at 0 until the extension 107 that was watching 288 sent another subscribe.

--
This message was sent by Atlassian JIRA
(v6.2#6252)