Review Board 1.7.16


DIALOG_INFO_XML stale (and timeout) notifiy subscriptions stop BLF's working on Grandstream GXP20xx phones.

Review Request #1813 - Created March 12, 2012 and updated

Alec Davis
1.8 and above
Reviewers
asterisk-dev
Asterisk
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@trusted             : Custom:q8601_a8612    State:InUse           Watchers  1
Debug output:

===Set the BLF state to InUse
- Executing [s@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@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@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@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@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@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@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@192.168.5.141"> version=6
===The BLF now has correct state of InUse.
In place on a 1.8 deployment for months, our production box with ~80 GXP phones, half of which are the older GXP20XX series.

Diff revision 2 (Latest)

1 2
1 2

  1. trunk/channels/chan_sip.c: Loading...
trunk/channels/chan_sip.c
Revision 376456 New Change
[20] 4373 lines
[+20] [+] static enum sip_result __sip_reliable_xmit(struct sip_pvt *p, uint32_t seqno, int resp, struct ast_str *data, int fatal, int sipmethod)
4374
{
4374
{
4375
	struct sip_pvt *p = (struct sip_pvt *)data;
4375
	struct sip_pvt *p = (struct sip_pvt *)data;
4376
	struct ast_channel *owner;
4376
	struct ast_channel *owner;
4377

    
   
4377

   
4378
	/* If this is a subscription, tell the phone that we got a timeout */
4378
	/* If this is a subscription, tell the phone that we got a timeout */
4379
	if (p->subscribed && p->subscribed != MWI_NOTIFICATION && p->subscribed != CALL_COMPLETION) {
4379
	if (p->subscribed && p->subscribed != MWI_NOTIFICATION && p->subscribed != CALL_COMPLETION && p->subscribed != DIALOG_INFO_XML) {
4380
		struct state_notify_data data = { 0, };
4380
		struct state_notify_data data = { 0, };
4381
		data.state = AST_EXTENSION_DEACTIVATED;
4381
		data.state = AST_EXTENSION_DEACTIVATED;
4382

    
   
4382

   
4383
		transmit_state_notify(p, &data, 1, TRUE);	/* Send last notification */
4383
		transmit_state_notify(p, &data, 1, TRUE);	/* Send last notification */
4384
		p->subscribed = NONE;
4384
		p->subscribed = NONE;
[+20] [20] 10047 lines
[+20] [+] static void state_notify_build_xml(struct state_notify_data *data, int full, const char *exten, const char *context, struct ast_str **tmp, struct sip_pvt *p, int subscribed, const char *mfrom, const char *mto)
14432
		}
14432
		}
14433
		ast_str_append(tmp, 0, "</tuple>\n</presence>\n");
14433
		ast_str_append(tmp, 0, "</tuple>\n</presence>\n");
14434
		break;
14434
		break;
14435
	case DIALOG_INFO_XML: /* SNOM subscribes in this format */
14435
	case DIALOG_INFO_XML: /* SNOM subscribes in this format */
14436
		ast_str_append(tmp, 0, "<?xml version=\"1.0\"?>\n");
14436
		ast_str_append(tmp, 0, "<?xml version=\"1.0\"?>\n");
14437
		ast_str_append(tmp, 0, "<dialog-info xmlns=\"urn:ietf:params:xml:ns:dialog-info\" version=\"%u\" state=\"%s\" entity=\"%s\">\n", p->dialogver, full ? "full" : "partial", mto);
14437
		ast_str_append(tmp, 0, "<dialog-info xmlns=\"urn:ietf:params:xml:ns:dialog-info\" version=\"%u\" state=\"%s\" entity=\"%s\">\n", 0, full ? "full" : "partial", mto);
14438
		if (data->state > 0 && (data->state & AST_EXTENSION_RINGING) && sip_cfg.notifyringing) {
14438
		if (data->state > 0 && (data->state & AST_EXTENSION_RINGING) && sip_cfg.notifyringing) {
14439
			const char *local_display = exten;
14439
			const char *local_display = exten;
14440
			char *local_target = ast_strdupa(mto);
14440
			char *local_target = ast_strdupa(mto);
14441
			const char *remote_display = exten;
14441
			const char *remote_display = exten;
14442
			/* It may seem odd to base the remote_target on the To header here,
14442
			/* It may seem odd to base the remote_target on the To header here,
[+20] [20] 19989 lines
  1. trunk/channels/chan_sip.c: Loading...

https://reviewboard.asterisk.org/ runs on a server provided by Digium, Inc. and uses bandwidth donated to the open source Asterisk community by API Digital Communications in Huntsville, AL USA.
Please report problems with this site to asteriskteam@digium.com.