1100863 - SimplePush: Adaptive ping doesn't work when it converge

Status: RESOLVED FIXED

(Core :: DOM: Push Subscriptions, defect)

Description

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

The adaptive ping of Push is not recalculated when it converges in a value and we change the time which Websocket can be open without transfers to other lower. We receive on logs the messages:

I/Gecko   (  210): -*- PushService.jsm: nextPingInterval=683437
I/Gecko   (  210): -*- PushService.jsm: lastGoodPing=1366875

But later, Push puts the keepalive timeout on 1366875:

I/Gecko   (  210): -*- PushService.jsm: Set alarm 1366875 in the future 554

Steps:

1.- Activate adaptive ping.
2.- Register an application on the Push Server.
3.- Wait to the adaptive ping converges in a value.
4.- Change the time which Websocket can be open without transfers to other lower.
5.- The keepalive timeout doesn't change when a ping isn't replied.

Comment 1

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Attachment: WIP Draft

Jorge, please, test this possible patch.

Comment 2

[Guillermo López :willyaranda (probably SLOW response)]

       // Try the pingInterval at least 3 times, just to be sure that the
       // calculated interval is not valid.
       if (this._pingIntervalRetryTimes[lastTriedPingInterval] < 2) {
         debug('pingInterval= ' + lastTriedPingInterval + ' tried only ' +
           this._pingIntervalRetryTimes[lastTriedPingInterval] + ' times');
         return;
       }

Fernando, have you seen this trace? It is supposed to check at least 3 times (if I remember correctly) if a ping is valid or not.

Comment 3

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

(In reply to Guillermo López :willyaranda from comment #2)
>        // Try the pingInterval at least 3 times, just to be sure that the
>        // calculated interval is not valid.
>        if (this._pingIntervalRetryTimes[lastTriedPingInterval] < 2) {
>          debug('pingInterval= ' + lastTriedPingInterval + ' tried only ' +
>            this._pingIntervalRetryTimes[lastTriedPingInterval] + ' times');
>          return;
>        }
> 
> Fernando, have you seen this trace? It is supposed to check at least 3 times
> (if I remember correctly) if a ping is valid or not.

Hi Willy !

Yes, but the problem appears when a valid ping interval is bellow the accepted gap. In that case, if the network changes and reduces that ping, the alghoritm doesn't re-start to recalculate it because _recalculatePing value. [1]

[1] http://mxr.mozilla.org/mozilla-central/source/dom/push/PushService.jsm#681

Comment 4

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Attachment: WIP branch

Comment 5

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Attachment: Proposed patch

Comment 6

[Nikhil Marathe [:nsm] (No longer reading bugmail, please needinfo?)]

Comment on attachment 8547536 [details] [diff] [review]
Proposed patch

Review of attachment 8547536 [details] [diff] [review]:
-----------------------------------------------------------------

r- for the wrong ordering and duplicate calculation. Please post a new patch without all the other formatting changes. I'll review it immediately.

::: dom/push/PushService.jsm
@@ +143,4 @@
>          index.get(aPushEndpoint).onsuccess = function setTxnResult(aEvent) {
>            aTxn.result = aEvent.target.result;
>            debug("Fetch successful " + aEvent.target.result);
> +        };

Nit: Not needed.

@@ +162,4 @@
>          aStore.get(aChannelID).onsuccess = function setTxnResult(aEvent) {
>            aTxn.result = aEvent.target.result;
>            debug("Fetch successful " + aEvent.target.result);
> +        };

Ditto.

@@ +193,4 @@
>              aTxn.result.push(cursor.value);
>              cursor.continue();
>            }
> +        };

Actually, get rid of all of them :)

@@ +484,5 @@
>    _upperLimit: 0,
>  
>    /**
> +   * Count the times WebSocket goes down without receiving Pings
> +   * so we can re-enable the ping recalculation alghoritm

Typo: algorithm.

@@ +686,4 @@
>        return;
>      }
>  
> +    if (!wsWentDown && this._wsWentDownCounter > 0) {

No need for the second part of the condition.

@@ +699,5 @@
> +        this._wsWentDownCounter = 0;
> +        this._recalculatePing = true;
> +        this._lastGoodPingIntervals = 0;
> +      }
> +      debug('We do not need to recalculate the ping, based on previous data');

I don't understand why this block is needed when the websocket has NOT disconnected. If you want to check that a recalculation is required, you can move the block below to above this block so that we know a recalculation is required and so this block does not run and early return.

@@ +743,5 @@
>  
>      let nextPingInterval;
>      let lastTriedPingInterval = prefs.get('pingInterval');
> +
> +    if (!this._recalculatePing && wsWentDown) {

Do you really need the |!this._recalculatePing| condition, or can it be just |if (wsWentDown)| ?
If you need it, please add a comment explaining why.

@@ +744,5 @@
>      let nextPingInterval;
>      let lastTriedPingInterval = prefs.get('pingInterval');
> +
> +    if (!this._recalculatePing && wsWentDown) {
> +      debug('Deshabilitado el recalculo, incrementamos contador');

English :)

@@ +747,5 @@
> +    if (!this._recalculatePing && wsWentDown) {
> +      debug('Deshabilitado el recalculo, incrementamos contador');
> +      this._wsWentDownCounter++;
> +      if (this._wsWentDownCounter > kWS_MAX_WENTDOWN) {
> +        debug('Ha fallado varias veces sin recibir datos, volvemos a iniciar el calculo de ping');

Here too.

@@ +750,5 @@
> +      if (this._wsWentDownCounter > kWS_MAX_WENTDOWN) {
> +        debug('Ha fallado varias veces sin recibir datos, volvemos a iniciar el calculo de ping');
> +        this._wsWentDownCounter = 0;
> +        this._lastGoodPingInterval = Math.floor(lastTriedPingInterval / 2);
> +        nextPingInterval = this._lastGoodPingInterval;

This calculation is done lower in the same function (now renamed to _save()). Why does it need to be done here?

Comment 7

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Thank you Nikhil .... Reviewing your comments I realized that I upload an incorrect version of the patch (spanish WIP comments, and duplicated code ...) Sorry for the inconveniences.

I'll fix the correct patch taking into account your comments and re-upload it asap.

Regards

Comment 8

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Attachment: Proposed patch

New version of the patch.

Before asking for review, I would like you to double-check if it's working properly.

Thanks in advance

Comment 9

[Jorge Prudencio [:jorgep]]

Hello Fernando,

I have tested the patch and it works perfectly :-)

I put here some traces:

02-13 10:37:57.138 I/Gecko   ( 1581): -*- PushService.jsm: Set alarm 180000 in the future 56
180000
02-13 10:40:57.278 I/Gecko   ( 1581): -*- PushService.jsm: Set alarm 270000 in the future 58
270000

--> Adaptive ping changed to 200000

02-13 10:45:42.398 I/Gecko   ( 1581): -*- PushService.jsm: Set alarm 270000 in the future 61
270000
02-13 10:50:27.548 I/Gecko   ( 1581): -*- PushService.jsm: Set alarm 180000 in the future 64
180000
02-13 10:53:27.688 I/Gecko   ( 1581): -*- PushService.jsm: Set alarm 180000 in the future 66
180000

--> Adaptive ping changed to 100000

02-13 10:56:42.798 I/Gecko   ( 1581): -*- PushService.jsm: Set alarm 180000 in the future 69
180000
02-13 10:59:57.938 I/Gecko   ( 1581): -*- PushService.jsm: Set alarm 90000 in the future 72
90000
02-13 11:01:28.088 I/Gecko   ( 1581): -*- PushService.jsm: Set alarm 135000 in the future 74
135000
02-13 11:05:31.745 I/Gecko   ( 1581): -*- PushService.jsm: Set alarm 90000 in the future 76
90000
02-13 11:09:06.359 I/Gecko   ( 1581): -*- PushService.jsm: Set alarm 90000 in the future 78
90000

Comment 10

[Jorge Prudencio [:jorgep]]

Remember that we should change kWS_MAX_WENTDOWN to 2 or 3.

Comment 11

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Attachment: Bug1100863_V2.patch

Thank you Jorge. As you suggested, I incremented kWS_MAX_WENTDOWN to 2.

Comment 12

[Nikhil Marathe [:nsm] (No longer reading bugmail, please needinfo?)]

Comment on attachment 8564123 [details] [diff] [review]
Bug1100863_V2.patch

Review of attachment 8564123 [details] [diff] [review]:
-----------------------------------------------------------------

::: dom/push/PushService.jsm
@@ +736,5 @@
>      let nextPingInterval;
>      let lastTriedPingInterval = prefs.get('pingInterval');
> +
> +    if (!this._recalculatePing && wsWentDown) {
> +      debug('Websocket disconnected without ping adaptative alghoritm running');

algorithm

@@ +739,5 @@
> +    if (!this._recalculatePing && wsWentDown) {
> +      debug('Websocket disconnected without ping adaptative alghoritm running');
> +      this._wsWentDownCounter++;
> +      if (this._wsWentDownCounter > kWS_MAX_WENTDOWN) {
> +        debug('Too many crashes. Reenabling ping adaptative algoritm');

s/crashes/disconnects.

@@ +742,5 @@
> +      if (this._wsWentDownCounter > kWS_MAX_WENTDOWN) {
> +        debug('Too many crashes. Reenabling ping adaptative algoritm');
> +        this._wsWentDownCounter = 0;
> +        this._recalculatePing = true;
> +        this._lastGoodPingIntervals = 0;

This variable is not used anywhere. Please remove it.

Comment 13

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Attachment: Proposed patch V3

Thank you Nikhil.
Nits fixed

Comment 14

[Carsten Book [:Tomcat]]

can we get a try run here ? thanks!

Comment 15

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

(In reply to Carsten Book [:Tomcat] from comment #14)
> can we get a try run here ? thanks!

https://treeherder.mozilla.org/#/jobs?repo=try&revision=53437785df05

Comment 16

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/eb836d0e41ff

Comment 17

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/eb836d0e41ff

Comment 18

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Comment on attachment 8564911 [details] [diff] [review]
Proposed patch V3

NOTE: Please see https://wiki.mozilla.org/Release_Management/B2G_Landing to better understand the B2G approval process and landings.

[Approval Request Comment]
Bug caused by (feature/regressing bug #): -
User impact if declined: Push server reconnections if carrier reduces the connection time
Testing completed: Y
Risk to taking this patch (and alternatives if risky): Low risk
String or UUID changes made by this patch: None

Comment 19

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-b2g37_v2_2/rev/250e2f0799e7

Comment 20

[Lina Butler [:lina]]

url:        https://hg.mozilla.org/integration/mozilla-inbound/rev/6379ad0797339835a87913fde9a30d458e64a241
changeset:  6379ad0797339835a87913fde9a30d458e64a241
user:       Kit Cambridge <[e-mail]>
date:       Tue Aug 11 07:30:38 2015 -0700
description:
Back out bug 1100863 and bug 1152264 for causing bug 1189729 on a CLOSED TREE. a=mhenretty,RyanVM

Comment 21

[Ryan VanderMeulen [:RyanVM]]

Does something need to land on v2.2 here still? AFAICT, this was only ever backed out from trunk.

Comment 22

[Lina Butler [:lina]]

Closing this out because the patch was backed out from Simple Push, and Web Push doesn't use adaptive pings.