908621 - Setting two alarms at the same time makes we lost reference to the first and we do not stop it (making it fire when we do not want)

Status: RESOLVED DUPLICATE of bug 909270

(Core :: DOM: Push Subscriptions, defect)

Description

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

We are doing some tests, and this is the first time we are seeing this:

08-23 12:06:30.006 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 822
08-23 12:06:30.046 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:06:30.046 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:06:30.307 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 823
08-23 12:06:30.407 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 824
08-23 12:07:30.015 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 824
08-23 12:07:30.065 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:07:30.065 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:07:30.325 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 825
08-23 12:07:30.415 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 826
08-23 12:08:30.003 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 826
08-23 12:08:30.174 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:08:30.174 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:08:30.344 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 827
08-23 12:08:30.424 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 828
08-23 12:09:30.012 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 828
08-23 12:09:30.072 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:09:30.092 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:09:30.342 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 829
08-23 12:09:30.432 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 830
08-23 12:10:30.021 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 830
08-23 12:10:30.081 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:10:30.091 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:10:30.361 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 831
08-23 12:10:30.451 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 832
08-23 12:11:29.999 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 832
08-23 12:11:30.089 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:11:30.099 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:11:30.339 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 833
08-23 12:11:30.429 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 834
08-23 12:12:30.008 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 834
08-23 12:12:30.098 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:12:30.108 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:12:30.338 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 835
08-23 12:12:30.448 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 836
08-23 12:13:29.996 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 836
08-23 12:13:30.116 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:13:30.116 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:13:30.336 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 837
08-23 12:13:30.417 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 838
08-23 12:14:30.005 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 838
08-23 12:14:30.125 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:14:30.135 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:14:30.315 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 839
08-23 12:14:30.415 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 840
08-23 12:15:30.003 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 840
08-23 12:15:30.033 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:15:30.033 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:15:30.324 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 841
08-23 12:15:30.414 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 842
08-23 12:16:30.012 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 842
08-23 12:16:30.032 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:16:30.032 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:16:30.342 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 843
08-23 12:16:30.442 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 844
08-23 12:17:30.000 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 844
08-23 12:17:30.140 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:17:30.160 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:17:30.351 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 845
08-23 12:17:30.421 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 846
08-23 12:18:29.999 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 846
08-23 12:18:30.049 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:18:30.049 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:18:30.299 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 847
08-23 12:18:30.389 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 848
08-23 12:19:30.007 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 848
08-23 12:19:30.157 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:19:30.167 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:19:30.328 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 849
08-23 12:19:30.428 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 850
08-23 12:20:29.996 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 850
08-23 12:20:30.066 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:20:30.066 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:20:30.376 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 851
08-23 12:20:30.466 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 852
08-23 12:21:30.014 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 852
08-23 12:21:30.074 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:21:30.084 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:21:30.365 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 853
08-23 12:21:30.455 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 854
08-23 12:22:30.013 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 854
08-23 12:22:30.083 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}
08-23 12:22:30.093 I/Gecko   (  107): -*- PushService.jsm: messageType not a string undefined
08-23 12:22:30.323 I/Gecko   (  107): -*- PushService.jsm: Set alarm 60000 in the future 855
08-23 12:22:30.423 I/Gecko   (  107): -*- PushService.jsm: Set alarm 1800000 in the future 856
08-23 12:23:30.001 I/Gecko   (  107): -*- PushService.jsm: Stopped existing alarm 856
08-23 12:23:30.092 I/Gecko   (  107): -*- PushService.jsm: wsOnMessageAvailable() {}


As you can see, there is a new pong message (because alarm fired and we send a ping), but the thing is that we are putting two alarms on the same moment: 60 and 1800 seconds.

Nikhil any thoughts?

Comment 1

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

What are the values of services.push.{requestTimeout, pingInterval, retryBaseInterval}?

Comment 2

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

Using the default values from b2g.js:

pref("services.push.retryBaseInterval", 5000);

pref("services.push.pingInterval", 1800000); // 30 minutes

pref("services.push.requestTimeout", 10000);

Comment 3

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

For example:

08-27 13:14:10.365 I/Gecko   (  109): -*- PushService.jsm: wsOnMessageAvailable() {"messageType":"register","status":200,"pushEndpoint":"https://push-nv.srv.openwebdevice.com:443/v1/notify/f9f61ac2aa928f0bbdf82a2fc30913babd5347702f35187c1ac854fb8809bb05","channelID":"8b9744cd-c51e-43eb-84c7-3a4183211aaf"}
08-27 13:14:10.375 I/Gecko   (  109): -*- PushService.jsm: handleRegisterReply()
08-27 13:14:10.395 I/Gecko   (  109): -*- PushService.jsm: Set alarm 1800000 in the future 185
08-27 13:14:10.445 I/Gecko   (  109): -*- PushService.jsm: wsOnMessageAvailable() {"messageType":"register","status":200,"pushEndpoint":"https://push-nv.srv.openwebdevice.com:443/v1/notify/07db3cbd28b2c8e3ac6bd9da61f4b718cc6337b790f1857a028d4de78eda267e","channelID":"74c13115-dd14-437c-88d5-17ae5c4df25e"}
08-27 13:14:10.445 I/Gecko   (  109): -*- PushService.jsm: Stopped existing alarm 185
08-27 13:14:10.455 I/Gecko   (  109): -*- PushService.jsm: handleRegisterReply()
08-27 13:14:10.455 I/Gecko   (  109): -*- PushService.jsm: wsOnMessageAvailable() {"messageType":"register","status":200,"pushEndpoint":"https://push-nv.srv.openwebdevice.com:443/v1/notify/3b5153724abb31eda718b7b221cc6663cb717a9588ae2cf3303814596787c60a","channelID":"74daf898-0f41-417a-bbb2-df986faf3177"}
08-27 13:14:10.465 I/Gecko   (  109): -*- PushService.jsm: handleRegisterReply()
08-27 13:14:10.505 I/Gecko   (  109): -*- PushService.jsm: Set alarm 1800000 in the future 186
08-27 13:14:10.676 I/Gecko   (  109): -*- PushService.jsm: Set alarm 1800000 in the future 187
08-27 13:14:10.766 I/Gecko   (  109): -*- PushService.jsm: Set alarm 1800000 in the future 188

It tries to set an alarm each time we have a message, but we should have a guard to only set an alarm at a given time.