Intermittent test_multiple_register.html,test_multiple_register_during_service_activation.html | could not register for push notification | Some test failed with error TypeError: result is null or Some test failed with error null

RESOLVED FIXED

Status

()

Core
DOM: Push Notifications
RESOLVED FIXED
3 years ago
2 years ago

People

(Reporter: KWierso, Unassigned)

Tracking

(Blocks: 1 bug, {intermittent-failure})

40 Branch
intermittent-failure
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox40 affected)

Details

(Reporter)

Description

3 years ago
10:09:21 INFO - 1 INFO TEST-START | dom/push/test/test_has_permissions.html
10:09:22 INFO - -*- Push.js: Push Constructor
10:09:22 INFO - MEMORY STAT vsize after test: 3374018560
10:09:22 INFO - MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
10:09:22 INFO - MEMORY STAT residentFast after test: 261914624
10:09:22 INFO - MEMORY STAT heapAllocated after test: 91060000
10:09:22 INFO - 2 INFO TEST-OK | dom/push/test/test_has_permissions.html | took 1217ms
10:09:22 INFO - 3 INFO TEST-START | dom/push/test/test_multiple_register.html
10:09:22 INFO - 4 INFO TEST-PASS | dom/push/test/test_multiple_register.html | getEndpoint should return null when app not subscribed.
10:09:22 INFO - 5 INFO TEST-UNEXPECTED-FAIL | dom/push/test/test_multiple_register.html | could not register for push notification - expected PASS
10:09:22 INFO - 6 INFO TEST-UNEXPECTED-FAIL | dom/push/test/test_multiple_register.html | Some test failed with error TypeError: result is null - expected PASS
10:09:22 INFO - MEMORY STAT vsize after test: 3380506624
10:09:22 INFO - MEMORY STAT residentFast after test: 265748480
10:09:22 INFO - MEMORY STAT heapAllocated after test: 92321456
10:09:22 INFO - 7 INFO TEST-OK | dom/push/test/test_multiple_register.html | took 114ms
10:09:23 INFO - 8 INFO TEST-START | dom/push/test/test_permissions.html
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)

Comment 3

3 years ago
I think we found that this was a server issues.  We upgraded our push server, and it causes some failures in the test infra.
Status: NEW → RESOLVED
Last Resolved: 3 years ago
Resolution: --- → WORKSFORME
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Status: RESOLVED → REOPENED
Resolution: WORKSFORME → ---
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
It seems to on the server side, or at push service is not able to connect to the server:

22:02:43 INFO - -*- PushServiceWebSocket.jsm: beginWSSetup()
22:02:43 INFO - -*- PushServiceWebSocket.jsm: serverURL: wss://push.services.mozilla.com/
22:02:50 INFO - -*- PushServiceWebSocket.jsm: wsOnStop()
22:02:50 INFO - -*- PushServiceWebSocket.jsm: Socket error 2152398861
Summary: Intermittent test_multiple_register.html | could not register for push notification | Some test failed with error TypeError: result is null → Intermittent test_multiple_register.html,test_multiple_register_during_service_activation.html | could not register for push notification | Some test failed with error TypeError: result is null or Some test failed with error null
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)

Comment 20

3 years ago
The log says: |PushServiceWebSocket.jsm: Socket error 2152398861| which is NS_ERROR_CONNECTION_REFUSED.
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)

Comment 53

3 years ago
10 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 5
* mozilla-central: 2
* fx-team: 2
* mozilla-aurora: 1

Platform breakdown:
* linux64: 6
* windowsxp: 3
* linux32: 1

For more details, see:
http://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1159963&startday=2015-09-28&endday=2015-10-04&tree=all

Comment 54

3 years ago
19 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 10
* fx-team: 5
* mozilla-central: 1
* mozilla-beta: 1
* mozilla-aurora: 1
* b2g-inbound: 1

Platform breakdown:
* linux64: 13
* windowsxp: 5
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1159963&startday=2015-10-05&endday=2015-10-11&tree=all
I have looked at  some logs

log:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=15438234
error:
 22:35:04     INFO -  2 INFO TEST-UNEXPECTED-FAIL | dom/push/test/test_data.html | Some test failed with error AbortError
 22:35:04     INFO -      runTest/<@dom/push/test/test_data.html:172:7
 22:35:04     INFO -      promise callback*runTest@dom/push/test/test_data.html:164:5
 22:35:04     INFO -      Async*@dom/push/test/test_data.html:176:1


function that is failing is:
  function start() {
    return navigator.serviceWorker.register("worker.js" + "?" + (Math.random()), {scope: "."})
    .then(swr => { registration = swr; return swr; });
  }
So I see 3 problems:

1) server not responding:

log:
https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=5012664
https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=4993209
test_data.html times out while waiting for the second notification.

in log
https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=5071747
test_data.html times out while waiting for the last notification.

in log:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=15431511
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=15297329
test_data.html successfully register for push notification (there is a answer from the push server) but never got any notification.

in log:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-beta&job_id=569089
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-release&job_id=104676
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-beta&job_id=556675
connection to the server timed out.



2) problem in comment 55:

log:
https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=5013888
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-aurora&job_id=1265089
is the same as in comment 55.

3) timeout waiting for unregister even though we are not waiting for the server to answer. 

in log:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=15318152
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=15289700
https://treeherder.mozilla.org/logviewer.html#?repo=b2g-inbound&job_id=2961964
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=15237030
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=2365763
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=15173234
https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=4973996
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=15228804
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=15192214
times out waiting for unregister to finish.



for problems 2 and 3 i would suggest to turn on some more logging to see what is happening
test_data.html is often timing out while waiting for the second message. If it is server random failure I would expect more randomness. We should turn on logging for couple of days to get some more info

Some of test_data.html failures are in bug 1206424
I have have failure with log turned on for test_data.html

The log:

this is the end of successful notification -  PushDB is succesfully updated:

-*- PushDB.jsm: update: Update successful for key ID 21a53390-2c0c-45f3-a296-5da7d70c4271"
-*- PushService.jsm: notifyApp() http://mochi.test:8888/tests/dom/push/test/
-*- PushServiceWebSocket.jsm: sendAck()
-*- PushServiceWebSocket.jsm: enqueue
-*- PushServiceWebSocket.jsm: Sending message: {\"messageType\":\"ack\",\"updates\":[{\"channelID\":\"21a53390-2c0c-45f3-a296-5da7d70c4271\"}]}


This is the next notification:

-*- PushServiceWebSocket.jsm: wsOnMessageAvailable() {\"version\": \"gAAAAABWIMIQkeDeuoJnjQWJIaf-IgPBGUEn8z5g6bm1hqVVNzKOEU1JxKutwpX7xo0F51mkSeCSA_xv4TmwZgIMrznBuC368zbBV1OSoWp5--Km6MHQmaV9N0-FevhcWX-IrEDu3ES1E58p9GabXmq3eiLDYDKWE5pdUU3fdIq5vS5jHEwog7E=\", \"channelID\": \"21a53390-2c0c-45f3-a296-5da7d70c4271\", \"messageType\": \"notification\"}
-*- PushServiceWebSocket.jsm: Reseting _retryFailCount and _pingIntervalRetryTimes
-*- PushService.jsm: Stopped existing alarm 7
AlarmService: remove(7, undefined)
AlarmService: _removeAlarmFromDb()
AlarmService: add(Fri Oct 16 2015 02:54:00 GMT-0700 (Pacific Standard Time))
-*- PushServiceWebSocket.jsm: handleNotificationReply()
-*- PushService.jsm: receivedPushMessage()
-*- PushDB.jsm: getByKeyID()
-*- PushDB.jsm: Fetch successful [object Object]
AlarmService: Callback after removing alarm from database.
AlarmService: Current alarm: null
AlarmService: Alarm queue: []
-*- PushDB.jsm: update: Ignoring invalid update for key ID 21a53390-2c0c-45f3-a296-5da7d70c4271

and the PushDB update fails.

This can be the reason for all failures in comment 56 (but not for the failures from comment 55)

I am push on try a patch with some more logging in the part that is failing, but I can not get it to fail...

Comment 60

3 years ago
13 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 6
* fx-team: 4
* b2g-inbound: 2
* try: 1

Platform breakdown:
* linux64: 8
* windowsxp: 2
* windows8-64: 2
* windows7-32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1159963&startday=2015-10-12&endday=2015-10-18&tree=all
(In reply to Dragana Damjanovic [:dragana] from comment #62)
> https://treeherder.mozilla.org/#/jobs?repo=try&revision=03b49d72a98e

In the linux debug build - the PushService part is correctly finished, even we have received unregister response from the push server (in WebSocket version we do not wait for that, when the record is deleted from db we return true)

So unregister of an existing subscription succeeded, and then the test tries to unregistr again which should return false.
This is the log for the last unregister:

"-*- PushService.jsm: receiveMessage(): Push:Unregister"}
"-*- PushService.jsm: unregister() {\"scope\":\"http://mochi.test:8888/tests/dom/push/test/\",\"requestID\":\"{fba214ad-a114-4c82-803b-16d6235557a4}\",\"originAttributes\":\"\"}"}
"-*- PushService.jsm: _unregister()"}
 "-*- PushDB.jsm: getByIdentifiers() { http://mochi.test:8888/tests/dom/push/test/, \"\" }"}

The last line is the db query that should return no record and than the function will return false as expected.
We do not have any more logging in PushService.jsm so it can be that:
1) db request never return (I think it is not that). There is no db error in the log
2) response between PushSevice and the test got lost :(

Comment 64

3 years ago
18 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 5
* fx-team: 4
* b2g-inbound: 4
* mozilla-aurora: 3
* try: 1
* mozilla-central: 1

Platform breakdown:
* linux64: 13
* linux32: 4
* windows7-32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1159963&startday=2015-10-19&endday=2015-10-25&tree=all

Comment 67

3 years ago
13 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 8
* mozilla-central: 2
* mozilla-beta: 1
* mozilla-aurora: 1
* fx-team: 1

Platform breakdown:
* linux64: 7
* windowsxp: 4
* linux32: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1159963&startday=2015-10-26&endday=2015-11-01&tree=all

Comment 68

3 years ago
6 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 5
* mozilla-central: 1

Platform breakdown:
* linux64: 6

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1159963&startday=2015-11-02&endday=2015-11-08&tree=all

Comment 69

3 years ago
7 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 5
* mozilla-central: 1
* fx-team: 1

Platform breakdown:
* linux64: 7

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1159963&startday=2015-11-16&endday=2015-11-22&tree=all

Comment 70

3 years ago
8 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 6
* try: 1
* b2g-inbound: 1

Platform breakdown:
* linux64: 7
* windows7-32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1159963&startday=2015-11-23&endday=2015-11-29&tree=all

Comment 71

3 years ago
11 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 5
* mozilla-aurora: 4
* mozilla-beta: 2

Platform breakdown:
* linux64: 8
* windowsxp: 2
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1159963&startday=2015-11-30&endday=2015-12-06&tree=all

Comment 72

3 years ago
5 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* fx-team: 3
* mozilla-inbound: 1
* mozilla-beta: 1

Platform breakdown:
* linux64: 4
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1159963&startday=2015-12-14&endday=2015-12-20&tree=all

Comment 73

3 years ago
5 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* try: 1
* mozilla-release: 1
* mozilla-inbound: 1
* mozilla-aurora: 1
* fx-team: 1

Platform breakdown:
* linux64: 2
* windows8-64: 1
* windows7-32: 1
* osx-10-6: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1159963&startday=2016-01-18&endday=2016-01-24&tree=all
Seeing this 20-30% of the time on OSX e10s as well.
Blocks: 1194533

Comment 75

2 years ago
195 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 107
* fx-team: 36
* mozilla-esr45: 24
* mozilla-aurora: 15
* mozilla-central: 5
* try: 4
* mozilla-beta: 4

Platform breakdown:
* linux64: 44
* windows7-32: 41
* osx-10-6: 27
* linux32: 25
* windowsxp: 22
* osx-10-10: 19
* windows8-64: 17

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1159963&startday=2016-02-29&endday=2016-03-06&tree=all
Fixed by bug 1244816.
Depends on: 1244816
Status: REOPENED → RESOLVED
Last Resolved: 3 years ago2 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.