Closed Bug 960762 Opened 6 years ago Closed 5 years ago

Intermittent test_bug931307.html | Test timed out | test_notification_storage.html | Test timed out

Categories

(Core :: DOM: Core & HTML, defect)

ARM
Gonk (Firefox OS)
defect
Not set

Tracking

()

RESOLVED FIXED
mozilla41
Tracking Status
firefox33 --- wontfix
firefox34 --- wontfix
firefox35 --- wontfix
firefox36 --- wontfix
firefox38 --- wontfix
firefox38.0.5 --- fixed
firefox39 --- fixed
firefox40 --- fixed
firefox41 --- fixed
firefox-esr31 --- wontfix
firefox-esr38 --- fixed
b2g-v2.0 --- wontfix
b2g-v2.0M --- wontfix
b2g-v2.1 --- wontfix
b2g-v2.1S --- wontfix
b2g-v2.2 --- fixed
b2g-master --- fixed

People

(Reporter: RyanVM, Assigned: gerard-majax)

References

Details

(Keywords: intermittent-failure, Whiteboard: [systemsfe])

Attachments

(2 files, 8 obsolete files)

79.06 KB, text/x-log
Details
5.18 KB, patch
gerard-majax
: review+
Details | Diff | Splinter Review
Those warnings don't look good.

https://tbpl.mozilla.org/php/getParsedLog.php?id=33109765&tree=Fx-Team

b2g_emulator_vm fx-team debug test mochitest-debug-13 on 2014-01-16 07:58:52 PST for push 0513569bea2c
slave: tst-linux64-ec2-067

08:36:07     INFO -  3114 INFO TEST-START | /tests/dom/tests/mochitest/notification/test_bug931307.html
08:36:07     INFO -  [Parent 673] WARNING: A control runnable was posted to a worker that is already shutting down!: file ../../../gecko/dom/workers/WorkerPrivate.cpp, line 2257
08:36:07     INFO -  [Parent 673] WARNING: A control runnable was posted to a worker that is already shutting down!: file ../../../gecko/dom/workers/WorkerPrivate.cpp, line 2257
08:36:07     INFO -  [Parent 673] WARNING: Failed to terminate!: file ../../../gecko/dom/workers/WorkerPrivate.cpp, line 2642
08:36:07     INFO -  [Parent 673] WARNING: A control runnable was posted to a worker that is already shutting down!: file ../../../gecko/dom/workers/WorkerPrivate.cpp, line 2257
08:36:07     INFO -  [Parent 673] WARNING: Failed to terminate!: file ../../../gecko/dom/workers/WorkerPrivate.cpp, line 2642
08:36:07     INFO -  [Parent 673] WARNING: A control runnable was posted to a worker that is already shutting down!: file ../../../gecko/dom/workers/WorkerPrivate.cpp, line 2257
08:36:07     INFO -  [Parent 673] WARNING: A control runnable was posted to a worker that is already shutting down!: file ../../../gecko/dom/workers/WorkerPrivate.cpp, line 2257
08:39:34     INFO -  [Parent 673] WARNING: Failed to terminate!: file ../../../gecko/dom/workers/WorkerPrivate.cpp, line 2642
08:39:34     INFO -  3115 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/notification/test_bug931307.html | Test timed out.
08:39:34     INFO -  3116 INFO TEST-INFO | MEMORY STAT vsize after test: 108990464
08:39:34     INFO -  3117 INFO TEST-INFO | MEMORY STAT residentFast after test: 51044352
08:39:34     INFO -  3118 INFO TEST-INFO | MEMORY STAT heapAllocated after test: 13909492
08:39:34     INFO -  3119 INFO TEST-END | /tests/dom/tests/mochitest/notification/test_bug931307.html | finished in 305790ms
08:39:34     INFO -  3120 INFO TEST-START | /tests/dom/tests/mochitest/notification/test_notification_basics.html
08:39:34     INFO -  3121 INFO TEST-INFO | /tests/dom/tests/mochitest/notification/test_notification_basics.html | ::Notification Tests:: - Test notification spec
08:39:34     INFO -  3122 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | Notification constructor exists
08:39:34     INFO -  3123 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | Notification.permission exists
08:39:34     INFO -  3124 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | Notification.requestPermission exists
08:39:34     INFO -  3125 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | Notification.get exists
08:39:34     INFO -  3126 INFO TEST-INFO | /tests/dom/tests/mochitest/notification/test_notification_basics.html | ::Notification Tests:: - Test blank requestPermission
08:39:34     INFO -  3127 INFO TEST-INFO | /tests/dom/tests/mochitest/notification/test_notification_basics.html | ::Notification Tests:: - Test requestPermission deny
08:39:34     INFO -  3128 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | Permission should be denied.
08:39:34     INFO -  3129 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | Permission should be denied.
08:39:34     INFO -  3130 INFO TEST-INFO | /tests/dom/tests/mochitest/notification/test_notification_basics.html | ::Notification Tests:: - Test requestPermission grant
08:39:34     INFO -  3131 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | Permission should be granted.
08:39:34     INFO -  3132 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | Permission should be granted
08:39:34     INFO -  3133 INFO TEST-INFO | /tests/dom/tests/mochitest/notification/test_notification_basics.html | ::Notification Tests:: - Test invalid requestPermission
08:39:34     INFO -  3134 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | Non callable arg to requestPermission should throw
08:39:34     INFO -  3135 INFO TEST-INFO | /tests/dom/tests/mochitest/notification/test_notification_basics.html | ::Notification Tests:: - Test create notification
08:39:34     INFO -  3136 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | Notification exists
08:39:34     INFO -  3137 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | onclick() should be null
08:39:34     INFO -  3138 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | onshow() should be null
08:39:34     INFO -  3139 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | onerror() should be null
08:39:34     INFO -  3140 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | onclose() should be null
08:39:34     INFO -  3141 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | close() should exist
08:39:34     INFO -  3142 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | auto should get set
08:39:34     INFO -  3143 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | lang should get set
08:39:34     INFO -  3144 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | body should get set
08:39:34     INFO -  3145 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | tag should get set
08:39:34     INFO -  3146 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | icon should get set
08:39:34     INFO -  System JS : ERROR (null):0 - uncaught exception: 2147500034
08:39:34     INFO -  3147 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | onshow handler should be called
08:45:07     INFO -  3148 INFO TEST-INFO | /tests/dom/tests/mochitest/notification/test_notification_basics.html | ::Notification Tests:: - Test closing a notification
08:45:07     INFO -  3149 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_basics.html | onclose handler should be called
08:45:07     INFO -  3150 INFO TEST-INFO | MEMORY STAT vsize after test: 108990464
08:45:07     INFO -  3151 INFO TEST-INFO | MEMORY STAT residentFast after test: 51896320
08:45:07     INFO -  3152 INFO TEST-INFO | MEMORY STAT heapAllocated after test: 14470232
08:45:07     INFO -  3153 INFO TEST-END | /tests/dom/tests/mochitest/notification/test_notification_basics.html | finished in 3673ms
08:45:07     INFO -  3154 INFO TEST-START | /tests/dom/tests/mochitest/notification/test_notification_storage.html
08:45:07     INFO -  3155 INFO TEST-INFO | /tests/dom/tests/mochitest/notification/test_notification_storage.html | ::Notification Tests:: - Test that Notifcation.get fulfills the promise
08:45:07     INFO -  3156 INFO TEST-PASS | /tests/dom/tests/mochitest/notification/test_notification_storage.html | should return a promise
08:45:07     INFO -  System JS : ERROR (null):0 - uncaught exception: 2147500034
08:45:07     INFO -  3157 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/notification/test_notification_storage.html | Test timed out.
08:45:07     INFO -  3158 INFO TEST-INFO | MEMORY STAT vsize after test: 108990464
08:45:07     INFO -  3159 INFO TEST-INFO | MEMORY STAT residentFast after test: 51601408
08:45:07     INFO -  3160 INFO TEST-INFO | MEMORY STAT heapAllocated after test: 14075688
08:45:07     INFO -  3161 INFO TEST-END | /tests/dom/tests/mochitest/notification/test_notification_storage.html | finished in 324721ms
They're harmless, they just warn or a predictable (and handled) race.
Component: DOM: Workers → DOM
Depends on: 931307
Blocks: 960126
No longer depends on: 960126
There are some interesting errors here in the logs:

1.) test_bug931307.html 
> 16:48:30     INFO -  01-17 00:16:13.603   672   672 E GeckoConsole: [JavaScript Warning: "reference to undefined property SysFile.free" {file: "resource://gre/modules/osfile/osfile_unix_back.jsm" line: 354}]

Not sure if this is causing the error, but seems fishy.


2.) test_notification_storage.html
> 16:48:30  WARNING -  01-17 00:20:54.903   720   720 E GeckoConsole: [JavaScript Error: "uncaught exception: 2147500034"]

Which is an NS_NOINTERFACE error, and uncaught errors are bad.


I'm probably going to need some help with this one, so I'll try and find someone next week.
Assignee: nobody → mhenretty
Blocks: 929122
Ryan,

This will take some time to investigate from my end. In the meantime, is the best way forward to add this test to the ignore list (testing/mochitest/b2g-debug.json) to get things green for bug 929122?
Flags: needinfo?(ryanvm)
Fine with me.
Flags: needinfo?(ryanvm)
Gregor, having intermittent issues for Notification.get mochitests for debug emulator. Disabling for now until I can get some help with the problem.
Attachment #8363221 - Flags: review?(anygregor)
Attachment #8363221 - Flags: review?(anygregor) → review+
Mike suggested I might like to take this.
Assignee: mhenretty → tclancy
Whiteboard: [leave open] → [leave open], [systemsfe]
Status: NEW → ASSIGNED
Keywords: leave-open
Whiteboard: [leave open], [systemsfe] → [systemsfe] [test disabled on B2G debug]
With all the recent fixes to notification and OS file, we might now have this problem anymore. I think we should re-enable this test. What do you think Alexandre?
Flags: needinfo?(lissyx+mozillians)
(In reply to Michael Henretty [:mhenretty] from comment #14)
> With all the recent fixes to notification and OS file, we might now have
> this problem anymore. I think we should re-enable this test. What do you
> think Alexandre?

I like enabling :)
Flags: needinfo?(lissyx+mozillians)
Is this test still disabled?
Flags: needinfo?(mhenretty)
I can't find it:

> alex@portable-alex:~/codaz/Mozilla/b2g/gecko$ git grep 'test_notification_storage.html'
> dom/tests/mochitest/notification/mochitest.ini:[test_notification_storage.html]
> alex@portable-alex:~/codaz/Mozilla/b2g/gecko$
Attached patch Re-enable Notification tests (obsolete) — Splinter Review
Re-enable the tests. I'll run this on try.
Flags: needinfo?(mhenretty)
Comment on attachment 8486498 [details] [diff] [review]
Re-enable Notification tests

First run green. I re-triggered a bunch of times to test the intermittent. In the meantime, Alexandre would you review this patch so we can land tomorrow if everything is clean?
Attachment #8486498 - Flags: review?(lissyx+mozillians)
I see one failure, that looks good :)
Comment on attachment 8486498 [details] [diff] [review]
Re-enable Notification tests

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

Try is green expect one failure that looks unrelated. I retriggered some tests to make sure.
Attachment #8486498 - Flags: review?(lissyx+mozillians) → review+
Try is green after retrigger: https://tbpl.mozilla.org/?tree=Try&rev=72d68410d538

The remaining failures are unrelated known intermittents, according to sherrifs.
Keywords: checkin-needed
https://hg.mozilla.org/integration/mozilla-inbound/rev/99cc09026985
Flags: in-testsuite+
Keywords: checkin-needed
Whiteboard: [systemsfe] [test disabled on B2G debug] → [systemsfe]
We can close this now.
Assignee: tclancy → mhenretty
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Keywords: leave-open
Resolution: --- → FIXED
Target Milestone: --- → mozilla35
Looks like the emulator is still having problems. Re-opening.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
This is happening often enough to be annoying. Let's disable and re-investigate.
Attachment #8363221 - Attachment is obsolete: true
Attachment #8489756 - Flags: review?(lissyx+mozillians)
Attachment #8489756 - Flags: review?(lissyx+mozillians) → review+
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/8cada343f1ab
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → FIXED
Whoops, forgot to put the leave-open keyword again.
Status: RESOLVED → REOPENED
Keywords: leave-open
Resolution: FIXED → ---
We really need to figure out what is going on with this test. Looks like it might even be perma-red.

https://tbpl.mozilla.org/?tree=Try&rev=c6cf2ee1bc9a
Attachment #8489756 - Attachment is obsolete: true
Attachment #8494031 - Flags: review?(lissyx+mozillians)
Comment on attachment 8494031 [details] [diff] [review]
[MC Patch] Disable notification storage tests for non-debug

r+ but it's time to stop this mess :(, one of us should investigate :)
Attachment #8494031 - Flags: review?(lissyx+mozillians) → review+
New try push, since the tree was busted I believe during the last try.

https://tbpl.mozilla.org/?tree=Try&rev=772eec00b67e
Attachment #8486498 - Attachment is obsolete: true
Sure got flaky on Android recently. Should I just save us all some time and go right to disabling the test?
Flags: needinfo?(mhenretty)
Target Milestone: mozilla35 → ---
Thanks Ryan, I would appreciate that.
Flags: needinfo?(mhenretty)
https://hg.mozilla.org/integration/fx-team/rev/8c8c73b587b5
Whiteboard: [systemsfe] → [systemsfe][test disabled on Android & B2G]
(In reply to Alexandre LISSY :gerard-majax from comment #280)
> Lets have a close look:
> https://treeherder.mozilla.org/#/jobs?repo=try&revision=54af6ee55a42

Cancelled, re-triggered with some more debug: https://treeherder.mozilla.org/#/jobs?repo=try&revision=f301e73e5885
Log for local run of comment 281
(In reply to Alexandre LISSY :gerard-majax from comment #281)
> (In reply to Alexandre LISSY :gerard-majax from comment #280)
> > Lets have a close look:
> > https://treeherder.mozilla.org/#/jobs?repo=try&revision=54af6ee55a42
> 
> Cancelled, re-triggered with some more debug:
> https://treeherder.mozilla.org/#/jobs?repo=try&revision=f301e73e5885

And we cannot get tests to run to investigte because of bug 1165317 :(
on a green run:
> 19:47:44     INFO -  *=*=* Notifications::MockServices: Received mock-notification-close-event with: {"http://mochi.test:8888#notag:{352844c6-ee38-4393-b057-adaf907bc728}":{"listener":{},"cookie":"notification:13","title":"test-title0.16122111858480914"}}

on a failed run:
> 19:34:11     INFO -  *=*=* Notifications::MockServices: Received mock-notification-close-event with: {}

on another failed run:
> 20:17:24     INFO -  *=*=* Notifications::MockServices: Received mock-notification-close-event with: {"http://mochi.test:8888#notag:{c6a4e4a0-02e1-461e-9658-907ebda0d04a}":{"listener":{},"cookie":"notification:10","title":"title1"},"http://mochi.test:8888#notag:{9c1d56a3-24c4-4f1f-94cb-22f5c02a55f4}":{"listener":{},"cookie":"notification:11","title":"title2"},"http://mochi.test:8888#notag:{929c930b-d788-404b-a285-193aa75ea892}":{"listener":{},"cookie":"notification:12","title":"title3"}}

So the race seems to be tied with MockServices. Any idea Michael?
Flags: needinfo?(mhenretty)
(In reply to Alexandre LISSY :gerard-majax from comment #288)
> https://treeherder.mozilla.org/#/jobs?repo=try&revision=39a67d044856

Full green \o/. Finally it was just a race within the tests :)
So it looks like the issue was due to a race between the mock services and the
close event: we triggered the call the the close event while the notification
was not yet within the hands of the mock alert service.
Attachment #8494031 - Attachment is obsolete: true
Attachment #8606638 - Flags: review?(mhenretty)
Attachment #8606638 - Attachment is obsolete: true
Attachment #8606638 - Flags: review?(mhenretty)
Attachment #8606645 - Flags: review?(mhenretty)
In,
(In reply to Alexandre LISSY :gerard-majax from comment #291)
> https://treeherder.mozilla.org/#/jobs?repo=try&revision=dc0535395142
> without the debug:
> https://treeherder.mozilla.org/#/jobs?repo=try&revision=06113997c8ad

We also re-enable on Android and B2G ICS Emulator. Retriggers are now green and stable over hundreds of run for:
 - linux64 debug M4
 - android4.0 debug M6
 - b2g ics emulator debug M16

This this should hopefully get rid also of bug 1076829
Blocks: 1076829
Depends on: 1159128
Rebased on mozilla-central after bug 1159128 landed
Attachment #8606645 - Attachment is obsolete: true
Attachment #8606645 - Flags: review?(mhenretty)
Attachment #8606725 - Flags: review?(mhenretty)
Assignee: mhenretty → lissyx+mozillians
Let's also have a look if we can make the other test non intermittent: https://treeherder.mozilla.org/#/jobs?repo=try&revision=949bb7146efb