[asterisk-dev] [Code Review] DIALOG_INFO_XML stale (and timeout) notifiy subscriptions stop BLF's working on Grandstream GXP20xx phones.

Fri Mar 8 00:18:02 CST 2013

-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviewboard.asterisk.org/r/1813/
-----------------------------------------------------------

(Updated March 8, 2013, 12:18 a.m.)

Review request for Asterisk Developers.

Changes
-------

This could be a new config option like buggymwi as used for Cisco phones.
Something like buggy_gxp20xx.

Not only does the stale subscription timeout mess up the new BLF version number, but so does a stale subscription updating a BLF.

Forcing the version number to "0" works around the stale subscription updates that happen until the subscription expires.
During this timeout period, the phone will get 2 updates for the same BLF, with both indicating the correct state 'confirmed' or 'terminated'.

Disabling the timeout notification, prevents the timeout notification setting state 'terminated;reason=timeout' which could incorrectly turn off a lit BLF.

Tested with newer GXP21xx series that don't have the problem (they reject the stale subscription as call-id doesn't match), and their BLF still operate correctly. 

Summary (updated)
-------

This issue is caused by review "handle_request_subscribe is too slow cause of iterating through all sip dialogs" https://reviewboard.asterisk.org/r/901/
commit http://svnview.digium.com/svn/asterisk?view=revision&revision=289623

Some phones (Grandstream GXP20XX series 1.2.5.3 firmware) if rebooted, loose the BLF lights due to the new subscription's "version" being less than the previous subscription's "version".
This happens the instant that asterisk timeouts the previous subscription - which has the much larger "version" sequence number.

The only way for the lights to start working again, is for the current subscription's "version" number to increment past the previous old "version" number.
That period of time could be huge, if the phone isn't rebooted for days.

The workaround has been to reboot the phone twice, within a few minutes of each reboot.
  1st time wait for the BLF's to fail (then reboot again) - which is the timeout period - a few minutes.
  2nd time the lights will work, then fail, then after a few minutes start working again.

This fix prevents the old subscription timeout from updating the phones "version" number. 

This issue doesn't affect the GXP21XX series.

Attempt to show issue byway of example below with some debug output showing call-id and version number.

astrid-test*CLI> core show hints

    -= Registered Asterisk Dial Plan Hints =-
            8601GXP0001 at trusted             : Custom:q8601_a8612    State:InUse           Watchers  1
Debug output:

===Set the BLF state to InUse
- Executing [s at macro-custom-agent-inout:13] Set("SIP/GXP0001-00000005", "DEVICE_STATE(Custom:q8601_a8612)=INUSE") in new stack
...
[Mar 14 11:01:39] NOTICE[10819]: chan_sip.c:13136 state_notify_build_xml: ALEC <dialog id="8601GXP0001" call-id="3c65aed02ae1d5df at 192.168.5.141"> version=5

=============
Reboot the phone, it gets a new BLF subscription.
=============
[Mar 14 11:02:30] NOTICE[10826]: chan_sip.c:13136 state_notify_build_xml: ALEC <dialog id="8601GXP0001" call-id="79956c0168125400 at 192.168.5.141"> version=0
===The BLF has correct state of InUse.

...
[Mar 14 11:05:00] NOTICE[10826]: chan_sip.c:13136 state_notify_build_xml: ALEC <dialog id="8601GXP0001" call-id="79956c0168125400 at 192.168.5.141"> version=1
===The BLF still has correct state of InUse.

...
The timeout 'last notification'
[Mar 14 11:05:09] NOTICE[10826]: chan_sip.c:13131 state_notify_build_xml: ALEC <dialog id="8601GXP0001" call-id="3c65aed02ae1d5df at 192.168.5.141" direction="recipient"> version=6
[Mar 14 11:05:09] NOTICE[10826]: chan_sip.c:3868 __sip_autodestruct: ALEC TIMEOUT of SIP subscription 3c65aed02ae1d5df at 192.168.5.141
===The BLF has incorrectly gone Idle.

...
[Mar 14 11:15:01] NOTICE[10826]: chan_sip.c:13136 state_notify_build_xml: ALEC <dialog id="8601GXP0001" call-id="79956c0168125400 at 192.168.5.141"> version=5
===The BLF is still incorrect at Idle.

    -- Registered SIP 'GXP0001' at 192.168.5.141:5066
[Mar 14 11:17:31] NOTICE[10826]: chan_sip.c:13136 state_notify_build_xml: ALEC <dialog id="8601GXP0001" call-id="79956c0168125400 at 192.168.5.141"> version=6
===The BLF now has correct state of InUse.

Diffs (updated)
-----

  trunk/channels/chan_sip.c 376456 

Diff: https://reviewboard.asterisk.org/r/1813/diff

Testing
-------

In place on a 1.8 deployment for months, our production box with ~80 GXP phones, half of which are the older GXP20XX series.

Thanks,

Alec

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.digium.com/pipermail/asterisk-dev/attachments/20130308/fcd633cb/attachment-0001.htm>