Intermittent test_bfcache.html | Test timed out

RESOLVED FIXED in Firefox 48

Status

()

Core
Web Speech
RESOLVED FIXED
2 years ago
a year ago

People

(Reporter: nigelb, Assigned: eeejay)

Tracking

({intermittent-failure})

unspecified
mozilla48
intermittent-failure
Points:
---

Firefox Tracking Flags

(firefox45 unaffected, firefox46 disabled, firefox47 disabled, firefox48 fixed, firefox-esr45 unaffected)

Details

(URL)

Attachments

(1 attachment, 1 obsolete attachment)

(Reporter)

Description

2 years ago
https://treeherder.mozilla.org/logviewer.html#?job_id=19349166&repo=mozilla-inbound


 21:33:21     INFO -  [Parent 2131] WARNING: Audio Buffer is not full by the end of the callback.: 'Available() == 0 || mSampleWriteOffset == 0', file /builds/slave/m-in-l64-d-0000000000000000000/build/src/dom/media/AudioBufferUtils.h, line 87
 21:33:28     INFO -  --DOMWINDOW == 16 (0x7f8345f88400) [pid = 2131] [serial = 8] [outer = (nil)] [url = about:blank]
 21:33:28     INFO -  --DOMWINDOW == 15 (0x7f8346bd7c00) [pid = 2131] [serial = 12] [outer = (nil)] [url = about:blank]
 21:33:28     INFO -  --DOMWINDOW == 14 (0x7f8345d09400) [pid = 2131] [serial = 9] [outer = (nil)] [url = about:blank]
 21:33:28     INFO -  --DOMWINDOW == 13 (0x7f8356d7d000) [pid = 2131] [serial = 2] [outer = (nil)] [url = about:blank]
 21:33:28     INFO -  --DOMWINDOW == 12 (0x7f833eb74400) [pid = 2131] [serial = 14] [outer = (nil)] [url = about:blank]
 21:33:32     INFO -  --DOMWINDOW == 10 (0x7f738aa18000) [pid = 2185] [serial = 2] [outer = (nil)] [url = about:blank]
 21:33:32     INFO -  --DOMWINDOW == 9 (0x7f7389c90400) [pid = 2185] [serial = 5] [outer = (nil)] [url = about:blank]
 21:33:32     INFO -  --DOMWINDOW == 8 (0x7f73892ebc00) [pid = 2185] [serial = 6] [outer = (nil)] [url = about:blank]
 21:33:32     INFO -  --DOMWINDOW == 7 (0x7f7388f25400) [pid = 2185] [serial = 9] [outer = (nil)] [url = about:blank]
 21:33:36     INFO -  --DOMWINDOW == 6 (0x7f7388f2b400) [pid = 2185] [serial = 10] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/media/webspeech/synth/test/file_bfcache_frame.html]
 21:38:18     INFO -  TEST-INFO | started process screentopng
 21:38:19     INFO -  TEST-INFO | screentopng: exit 0
 21:38:19     INFO -  24 INFO SimpleTest START
 21:38:19     INFO -  25 INFO TEST-UNEXPECTED-FAIL | dom/media/webspeech/synth/test/test_bfcache.html | Test timed out.
 21:38:19     INFO -      reportError@SimpleTest/TestRunner.js:114:7
 21:38:19     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:134:7
 21:38:19     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:155:5
 21:38:19     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:155:5
 21:38:19     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:155:5
 21:38:19     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:155:5
 21:38:19     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:155:5
 21:38:19     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:155:5
 21:38:19     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:155:5
 21:38:19     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:155:5
 21:38:19     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:155:5
 21:38:19     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:155:5
 21:38:19     INFO -      TestRunner.runTests@SimpleTest/TestRunner.js:366:5
 21:38:19     INFO -      RunSet.runtests@SimpleTest/setup.js:188:3
 21:38:19     INFO -      RunSet.runall@SimpleTest/setup.js:167:5
 21:38:19     INFO -      hookupTests@SimpleTest/setup.js:260:5
 21:38:19     INFO -  parseTestManifest@http://mochi.test:8888/manifestLibrary.js:36:5
 21:38:19     INFO -  getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:49:11
 21:38:19     INFO -  EventHandlerNonNull*getTestManifest@http://mochi.test:8888/manifestLibrary.js:45:3
 21:38:19     INFO -      hookup@SimpleTest/setup.js:240:5
 21:38:19     INFO -  EventHandlerNonNull*@http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&hideResultsTable=1&manifestFile=tests.json&dumpOutputDirectory=%2Ftmp:11:1
 21:38:19     INFO -  MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
 21:38:19     INFO -  MEMORY STAT | vsize 508MB | residentFast 89MB | heapAllocated 15MB
 21:38:19     INFO -  26 INFO TEST-OK | dom/media/webspeech/synth/test/test_bfcache.html | took 301050ms
 21:38:19     INFO -  ++DOMWINDOW == 7 (0x7f73892de800) [pid = 2185] [serial = 12] [outer = 0x7f7389c8f800]
 21:38:19     INFO -  27 INFO TEST-START | dom/media/webspeech/synth/test/test_global_queue.html
 21:38:19     INFO -  ++DOMWINDOW == 8 (0x7f73892e0800) [pid = 2185] [serial = 13] [outer = 0x7f7389c8f800]
 21:38:19     INFO -  ++DOCSHELL 0x7f7389161800 == 4 [pid = 2185] [id = 4]
 21:38:19     INFO -  ++DOMWINDOW == 9 (0x7f7388e4d000) [pid = 2185] [serial = 14] [outer = (nil)]
 21:38:19     INFO -  ++DOMWINDOW == 10 (0x7f7389c93800) [pid = 2185] [serial = 15] [outer = 0x7f7388e4d000]
 21:38:20     INFO -  --DOCSHELL 0x7f7389158800 == 3 [pid = 2185] [id = 3]
 21:38:20     INFO -  ++DOMWINDOW == 11 (0x7f738a755000) [pid = 2185] [serial = 16] [outer = 0x7f7388e4d000]
 21:38:20     INFO -  ++DOCSHELL 0x7f738a79b000 == 4 [pid = 2185] [id = 5]
 21:38:20     INFO -  ++DOMWINDOW == 12 (0x7f738a75bc00) [pid = 2185] [serial = 17] [outer = (nil)]
 21:38:20     INFO -  ++DOCSHELL 0x7f738a7a5800 == 5 [pid = 2185] [id = 6]
 21:38:20     INFO -  ++DOMWINDOW == 13 (0x7f738a7cc000) [pid = 2185] [serial = 18] [outer = (nil)]
 21:38:20     INFO -  ++DOMWINDOW == 14 (0x7f7388e5b000) [pid = 2185] [serial = 19] [outer = 0x7f738a75bc00]
 21:38:20     INFO -  ++DOMWINDOW == 15 (0x7f738a7cf800) [pid = 2185] [serial = 20] [outer = 0x7f738a7cc000]
 21:38:20     INFO -  [Child 2185] WARNING: No inner window available!: file /builds/slave/m-in-l64-d-0000000000000000000/build/src/dom/base/nsGlobalWindow.cpp, line 9258
 21:38:21     INFO -  MEMORY STAT | vsize 509MB | residentFast 90MB | heapAllocated 17MB
 21:38:21     INFO -  28 INFO TEST-OK | dom/media/webspeech/synth/test/test_global_queue.html | took 1986ms
 21:38:21     INFO -  ++DOMWINDOW == 16 (0x7f7388e56c00) [pid = 2185] [serial = 21] [outer = 0x7f7389c8f800]
 21:38:21     INFO -  29 INFO TEST-START | dom/media/webspeech/synth/test/test_global_queue_cancel.html
 21:38:21     INFO -  [Parent 2131] WARNING: Audio Buffer is not full by the end of the callback.: 'Available() == 0 || mSampleWriteOffset == 0', file /builds/slave/m-in-l64-d-0000000000000000000/build/src/dom/media/AudioBufferUtils.h, line 87
 21:38:22     INFO -  ++DOMWINDOW == 17 (0x7f738a9c9c00) [pid = 2185] [serial = 22] [outer = 0x7f7389c8f800]
 21:38:22     INFO -  ++DOCSHELL 0x7f7389cb1800 == 6 [pid = 2185] [id = 7]
 21:38:22     INFO -  ++DOMWINDOW == 18 (0x7f738a9cc400) [pid = 2185] [serial = 23] [outer = (nil)]
 21:38:22     INFO -  ++DOMWINDOW == 19 (0x7f738bbcfc00) [pid = 2185] [serial = 24] [outer = 0x7f738a9cc400]
 21:38:22     INFO -  ++DOMWINDOW == 20 (0x7f73892e6000) [pid = 2185] [serial = 25] [outer = 0x7f738a9cc400]
 21:38:22     INFO -  ++DOCSHELL 0x7f738a7a0000 == 7 [pid = 2185] [id = 8]
 21:38:22     INFO -  ++DOMWINDOW == 21 (0x7f7388f2e800) [pid = 2185] [serial = 26] [outer = (nil)]
 21:38:22     INFO -  ++DOCSHELL 0x7f738aa42800 == 8 [pid = 2185] [id = 9]
 21:38:22     INFO -  ++DOMWINDOW == 22 (0x7f7389c90400) [pid = 2185] [serial = 27] [outer = (nil)]
 21:38:22     INFO -  ++DOMWINDOW == 23 (0x7f738a75b800) [pid = 2185] [serial = 28] [outer = 0x7f7388f2e800]
 21:38:22     INFO -  ++DOMWINDOW == 24 (0x7f738a91c000) [pid = 2185] [serial = 29] [outer = 0x7f7389c90400]
 21:38:22     INFO -  MEMORY STAT | vsize 510MB | residentFast 91MB | heapAllocated 18MB

Comment 1

2 years ago
17 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 13
* mozilla-central: 2
* b2g-inbound: 2

Platform breakdown:
* linux64: 5
* b2g-emu-ics: 5
* android-2-3-armv7-api9: 5
* linux32: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-06&endday=2016-01-06&tree=all
(Assignee)

Updated

2 years ago
Assignee: nobody → eitan

Comment 2

2 years ago
39 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 24
* fx-team: 9
* b2g-inbound: 4
* mozilla-central: 2

Platform breakdown:
* b2g-emu-ics: 18
* android-2-3-armv7-api9: 11
* linux64: 7
* linux32: 2
* android-4-3-armv7-api11: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-07&endday=2016-01-07&tree=all

Comment 3

2 years ago
37 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 15
* mozilla-central: 8
* try: 5
* b2g-inbound: 5
* fx-team: 4

Platform breakdown:
* b2g-emu-ics: 13
* linux32: 9
* linux64: 7
* android-2-3-armv7-api9: 7
* android-4-3-armv7-api11: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-08&endday=2016-01-08&tree=all
(Assignee)

Comment 4

2 years ago
I suspect that the pageshow listener on the iframe is not getting called. Investigating further...

Comment 5

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

Repository breakdown:
* mozilla-inbound: 63
* fx-team: 21
* mozilla-central: 14
* b2g-inbound: 11
* try: 5

Platform breakdown:
* b2g-emu-ics: 43
* android-2-3-armv7-api9: 27
* linux64: 25
* linux32: 16
* android-4-3-armv7-api11: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-04&endday=2016-01-10&tree=all

Comment 6

2 years ago
33 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 14
* fx-team: 12
* b2g-inbound: 5
* try: 2

Platform breakdown:
* b2g-emu-ics: 11
* linux64: 7
* linux32: 5
* android-4-3-armv7-api11: 4
* android-2-3-armv7-api9: 4
* windows8-64: 1
* windows7-32: 1

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

Comment 7

2 years ago
29 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 17
* b2g-inbound: 7
* fx-team: 4
* b2g-ota: 1

Platform breakdown:
* b2g-emu-ics: 17
* linux32: 6
* linux64: 3
* android-2-3-armv7-api9: 2
* android-4-3-armv7-api11: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-12&endday=2016-01-12&tree=all
I have a timeout of this test recorded in rr. I'll look into it shortly.

Comment 9

2 years ago
27 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 19
* mozilla-central: 3
* fx-team: 2
* b2g-inbound: 2
* try: 1

Platform breakdown:
* linux32: 8
* b2g-emu-ics: 8
* android-2-3-armv7-api9: 8
* linux64: 2
* android-4-3-armv7-api11: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-13&endday=2016-01-13&tree=all
(Assignee)

Comment 10

2 years ago
Created attachment 8707960 [details] [diff] [review]
Robustify synth/test/test_bfcache.html to avoid intermittent timeouts.

Looks like bageshow events don't always work. onload is not an option because it makes pages not get cached. Simply putting the script in the body of the document is good enough for these tests.
Attachment #8707960 - Flags: review?(bugs)
Adding event listener for load doesn't affect to bfcache.
It is  beforeunload and unload listeners which do.
(Assignee)

Comment 12

2 years ago
(In reply to Robert O'Callahan (:roc) (offline Jan 16-24)  (Mozilla Corporation) from comment #8)
> I have a timeout of this test recorded in rr. I'll look into it shortly.

I missed that. Thanks. My fix is mostly a misundereducated guess. Logs show no speech ever starting, so I assume the JS call to speech are not executed.

(In reply to Olli Pettay [:smaug] from comment #11)
> Adding event listener for load doesn't affect to bfcache.
> It is  beforeunload and unload listeners which do.

Ah, right. Either way, no need for onload or onpageshow.
oh, silly me. I reviewed this and wasn't thinking the actual test is in iframe. That prevents all bfache. bfcache is for top level navigations only. But anyhow, the test is useful test, files just named wrongly.
Comment on attachment 8707960 [details] [diff] [review]
Robustify synth/test/test_bfcache.html to avoid intermittent timeouts.

But still, the existing code should work.
Did you perhaps push to try a version which logs when various events are handled.
If pageshow is not being dispatched, something is really broken.

So could you explain why the change is supposed to fix something.
Attachment #8707960 - Flags: review?(bugs) → review-

Comment 15

2 years ago
51 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 20
* try: 16
* fx-team: 10
* b2g-inbound: 3
* mozilla-central: 2

Platform breakdown:
* b2g-emu-ics: 15
* android-2-3-armv7-api9: 12
* linux32: 7
* android-4-3-armv7-api11: 7
* linux64: 5
* osx-10-6: 3
* windows7-32: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-14&endday=2016-01-14&tree=all
(In reply to Robert O'Callahan (:roc) (offline Jan 16-24)  (Mozilla Corporation) from comment #8)
> I have a timeout of this test recorded in rr. I'll look into it shortly.

I didn't get to this before I go on PTO for a week. I'll get back to it after that.

Comment 17

2 years ago
36 automation job failures were associated with this bug yesterday.

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

Platform breakdown:
* b2g-emu-ics: 12
* linux64: 8
* android-2-3-armv7-api9: 7
* linux32: 6
* android-4-3-armv7-api11: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-15&endday=2016-01-15&tree=all

Comment 18

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

Repository breakdown:
* mozilla-inbound: 112
* fx-team: 37
* b2g-inbound: 25
* try: 22
* mozilla-central: 11
* b2g-ota: 1

Platform breakdown:
* b2g-emu-ics: 77
* android-2-3-armv7-api9: 41
* linux32: 36
* linux64: 31
* android-4-3-armv7-api11: 17
* windows7-32: 3
* osx-10-6: 2
* windows8-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-11&endday=2016-01-17&tree=all

Comment 19

2 years ago
19 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 14
* fx-team: 2
* try: 1
* mozilla-central: 1
* b2g-inbound: 1

Platform breakdown:
* b2g-emu-ics: 6
* android-2-3-armv7-api9: 6
* linux32: 4
* android-4-3-armv7-api11: 2
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-18&endday=2016-01-18&tree=all
(Assignee)

Comment 20

2 years ago
OK, did some digging. Managed to reproduce this fairly reliably with cpulimit and capture it in rr. It looks like the MediaStreamListener does not get notified in a timely fashion after SourceMediaStream::EndAllTrackAndFinish is called.

A quick fix for this test would be to use an indirect audio service (tested locally, and I think it fixes this timeout). But, I imagine there may be something in MSG worth fixing?

Comment 21

2 years ago
28 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 14
* fx-team: 8
* mozilla-central: 3
* b2g-inbound: 2
* try: 1

Platform breakdown:
* b2g-emu-ics: 9
* android-2-3-armv7-api9: 7
* linux32: 6
* linux64: 3
* android-4-3-armv7-api11: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-19&endday=2016-01-19&tree=all
(Assignee)

Comment 22

2 years ago
Disregard the previous comment :P
(Assignee)

Comment 23

2 years ago
At least in the rr recording it looks like the timeout happens between the FakeDirectAudioSynth::Speak and the time it takes the nested runnable to actually run. I'm not convinced this is the same orange failure.

Comment 24

2 years ago
35 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 17
* b2g-inbound: 11
* fx-team: 7

Platform breakdown:
* b2g-emu-ics: 15
* android-2-3-armv7-api9: 9
* linux32: 8
* android-4-3-armv7-api11: 2
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-20&endday=2016-01-20&tree=all

Comment 25

2 years ago
40 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 26
* b2g-inbound: 7
* fx-team: 5
* try: 1
* mozilla-central: 1

Platform breakdown:
* b2g-emu-ics: 17
* android-2-3-armv7-api9: 13
* linux64: 7
* android-4-3-armv7-api11: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-21&endday=2016-01-21&tree=all

Comment 26

2 years ago
76 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 53
* fx-team: 12
* try: 5
* b2g-inbound: 4
* mozilla-central: 2

Platform breakdown:
* b2g-emu-ics: 29
* linux64: 27
* android-2-3-armv7-api9: 14
* linux32: 5
* android-4-3-armv7-api11: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-22&endday=2016-01-22&tree=all

Comment 27

2 years ago
We got a crash with a stack in this test over here:

  https://bugzilla.mozilla.org/show_bug.cgi?id=1242113

Related?
See Also: → bug 1242113

Comment 28

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

Repository breakdown:
* mozilla-inbound: 140
* fx-team: 45
* b2g-inbound: 26
* try: 12
* mozilla-central: 12

Platform breakdown:
* b2g-emu-ics: 85
* linux64: 55
* android-2-3-armv7-api9: 54
* linux32: 27
* android-4-3-armv7-api11: 14

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-18&endday=2016-01-24&tree=all

Comment 29

2 years ago
38 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 17
* b2g-inbound: 7
* fx-team: 6
* mozilla-central: 5
* mozilla-aurora: 2
* try: 1

Platform breakdown:
* linux64: 21
* android-2-3-armv7-api9: 13
* b2g-emu-ics: 4

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-25&endday=2016-01-25&tree=all

Comment 30

2 years ago
49 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 31
* fx-team: 16
* try: 1
* mozilla-central: 1

Platform breakdown:
* linux64: 36
* android-2-3-armv7-api9: 11
* android-4-3-armv7-api11: 2

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

Comment 31

2 years ago
36 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 31
* fx-team: 3
* try: 1
* mozilla-central: 1

Platform breakdown:
* linux64: 19
* android-2-3-armv7-api9: 10
* android-4-3-armv7-api11: 4
* linux32: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-27&endday=2016-01-27&tree=all

Comment 32

2 years ago
37 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 24
* fx-team: 9
* try: 2
* mozilla-aurora: 2

Platform breakdown:
* linux64: 21
* android-2-3-armv7-api9: 9
* android-4-3-armv7-api11: 5
* linux32: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-28&endday=2016-01-28&tree=all

Comment 33

2 years ago
42 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 26
* fx-team: 9
* mozilla-central: 4
* try: 2
* mozilla-aurora: 1

Platform breakdown:
* linux64: 30
* android-2-3-armv7-api9: 10
* osx-10-6: 1
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-29&endday=2016-01-29&tree=all

Comment 34

2 years ago
15 automation job failures were associated with this bug yesterday.

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

Platform breakdown:
* linux64: 13
* linux32: 1
* android-2-3-armv7-api9: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-30&endday=2016-01-30&tree=all
Congratulations on making it to the top of the intermittent-failure list by a considerable margin. Your award is a skip-if.
Whiteboard: [test disabled on Linux][test disabled on Android]
Keywords: leave-open

Comment 36

2 years ago
https://hg.mozilla.org/integration/mozilla-inbound/rev/1d8e7cf8a896

Comment 37

2 years ago
https://hg.mozilla.org/integration/mozilla-inbound/rev/a05aefe2c48a
"Oops."

Comment 39

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

Repository breakdown:
* mozilla-inbound: 146
* fx-team: 54
* mozilla-central: 13
* try: 8
* b2g-inbound: 7
* mozilla-aurora: 5

Platform breakdown:
* linux64: 151
* android-2-3-armv7-api9: 58
* android-4-3-armv7-api11: 11
* linux32: 7
* b2g-emu-ics: 4
* osx-10-6: 1
* android-4-3-armv7-api15: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-01-25&endday=2016-01-31&tree=all

Comment 40

2 years ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/1d8e7cf8a896
https://hg.mozilla.org/mozilla-central/rev/a05aefe2c48a
With the help of rr chaos mode, I reproduced a timeout which happens because the "hi!" utterance never fires its end event. That happens like so:

-- nsFakeSynthServices calls into nsSpeechTask::Setup which calls mStream->AddListener. This queues a message to be sent to the graph at the next main-thread stable state.
-- nsFakeSynthServices calls into nsSpeechTask::SendAudioImpl with aDataLen > 0. We stuff some data into the SourceMediaStream queue.
-- nsFakeSynthServices calls into nsSpeechTask::SendAudioImpl with aDataLen == 0. We mark the SourceMediaStream tracks and stream ended from the producer's point of view.
-- The next main-thread stable state occurs. An MSG iteration has already started and is updating stream order, i.e. messages have already been processed, but SourceMediaStream::ExtractPendingInput has not yet been called.
-- So, SourceMediaStream::ExtractPendingInput runs and the AddListener message has not yet been processed.
-- In the same MSG iteration, MediaStreamGraphImpl::UpdateCurrentTimeForStreams sets stream->mNotifiedFinished and stream->mNotifiedBlocked (I guess because the fake utterance is very short and we're able to play it out in a single MSG iteration).
-- In the next MSG iteration, we process AddListener in MediaStream::AddListenerImpl. We call listener->NotifyBlockingChanged(BLOCKED). SynthStreamListener::NotifyBlockingChanged ignores that so nsSpeechTask never changes to STATE_SPEAKING!
-- MediaStream::AddListenerImpl calls listener->NotifyEvent(EVENT_FINISHED) which dispatches a DispatchEndInner. 
DispatchEndImpl runs and sees the nsSpeechTask is still in STATE_PENDING, and sets it to NONE without dispatching an "end" event.
I guess the core issue here is around the expectation that adding a listener can take effect after the MSG has processed the audio data, even though the audio data is put into the SourceMediaStream after adding the listener. Perhaps the best way to fix that would be to make SourceMediaStream's data-sending methods queue messages for the next stable state, like MSG control messages, when called on the main thread. But that's a bit complicated and potentially ugly.

Overall it might be a better fix just say that expectation is unjustified, and have SynthStreamListener::NotifyEvent(EVENT_FINISHED) enter the mStarted state and dispatch a DoNotifyStarted if NotifyBlockingChanged hasn't already done so. Sound OK, Eitan?

BTW I have some other timed-out rr runs which I'll take a look at to see if they have the same cause.
Flags: needinfo?(eitan)
All 4 other "Test timed out" runs are because of the same issue.

I don't know for sure that this issue is what caused the timeouts in test automation, but it's worth fixing.

Comment 44

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

Repository breakdown:
* mozilla-aurora: 15
* b2g-inbound: 2

Platform breakdown:
* linux64: 5
* android-2-3-armv7-api9: 4
* osx-10-6: 3
* linux32: 3
* android-4-3-armv7-api15: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-02-01&endday=2016-02-07&tree=all
(In reply to Robert O'Callahan (:roc) (Mozilla Corporation) from comment #42)
> I guess the core issue here is around the expectation that adding a listener
> can take effect after the MSG has processed the audio data, even though the
> audio data is put into the SourceMediaStream after adding the listener.

Oops, I mixed this up.

The expectation of the nsSpeechTask code is that if you add a listener and then insert audio data into the SourceMediaStream, the listener will be added before the data is processed. That expectation is currently invalid.
(Assignee)

Comment 46

2 years ago
Created attachment 8717640 [details] [diff] [review]
Notify synth start if we get a finished event without a blocking-changed event. r?roc

MozReview-Commit-ID: BJSQOiyXmRh
Attachment #8707960 - Attachment is obsolete: true
Attachment #8717640 - Flags: review?(roc)
(Assignee)

Comment 47

2 years ago
Thanks for the suggestion roc. I think this is what I saw in comment #20 in my own rr recording. Wasn't entirely convinced it was the same failure as the one on treeherder, because inserting LOG_NSPR_MODULES=SpeechSYnthesis:5 into the treeherder tests did not show output that would suggest this.

OTOH, using the indirect speech service that doesn't use MSG seemed to fix this. So maybe it is.

Anyway, it is still worth a fix as you say. Patch above.
Flags: needinfo?(eitan)
Comment on attachment 8717640 [details] [diff] [review]
Notify synth start if we get a finished event without a blocking-changed event. r?roc

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

::: dom/media/webspeech/synth/nsSpeechTask.cpp
@@ +60,5 @@
>          {
> +          if (!mStarted) {
> +            nsCOMPtr<nsIRunnable> startRunnable =
> +              NS_NewRunnableMethod(this, &SynthStreamListener::DoNotifyStarted);
> +              aGraph->DispatchToMainThreadAfterStreamStateUpdate(startRunnable.forget());

I'd set mStarted to true here just for sanity's sake.
Attachment #8717640 - Flags: review?(roc) → review+

Comment 49

2 years ago
https://hg.mozilla.org/integration/mozilla-inbound/rev/6d0825ced35d

Comment 50

2 years ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/6d0825ced35d

Comment 51

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

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

Platform breakdown:
* linux64: 7
* linux32: 5
* android-2-3-armv7-api9: 5
* osx-10-6: 2
* android-4-3-armv7-api15: 2
* windowsxp: 1

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

Comment 52

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

Repository breakdown:
* mozilla-aurora: 11

Platform breakdown:
* linux64: 5
* osx-10-6: 2
* linux32: 2
* android-4-3-armv7-api15: 1
* android-2-3-armv7-api9: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-02-22&endday=2016-02-28&tree=all

Comment 53

2 years ago
196 automation job failures were associated with this bug yesterday.

Repository breakdown:
* fx-team: 193
* mozilla-aurora: 3

Platform breakdown:
* linux64: 193
* linux32: 2
* android-2-3-armv7-api9: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-02-29&endday=2016-02-29&tree=all
Looks like you never re-enabled this test on trunk? Also, can you request Aurora approval for this uplift assuming the risk is low enough to warrant it?
status-firefox45: --- → wontfix
status-firefox46: --- → affected
status-firefox47: --- → affected
Flags: needinfo?(eitan)
Keywords: leave-open
Whiteboard: [test disabled on Linux][test disabled on Android]

Comment 55

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

Repository breakdown:
* fx-team: 193
* mozilla-aurora: 18
* try: 2

Platform breakdown:
* linux64: 200
* android-2-3-armv7-api9: 5
* linux32: 4
* osx-10-6: 2
* android-4-3-armv7-api15: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-02-29&endday=2016-03-06&tree=all

Comment 56

a year ago
https://hg.mozilla.org/integration/mozilla-inbound/rev/53538223cf05
(Assignee)

Comment 57

a year ago
Did a try run. It looks good, so I am re-enabling the test.

https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=53538223cf05

I missed the train for the previous Aurora, so there is no point in uplifting the fix.
Flags: needinfo?(eitan)

Comment 58

a year ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/53538223cf05
Status: NEW → RESOLVED
Last Resolved: a year ago
status-firefox48: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla48
10 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-beta: 7
* mozilla-aurora: 3

Platform breakdown:
* linux64: 5
* android-2-3-armv7-api9: 3
* osx-10-6: 1
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-03-07&endday=2016-03-13&tree=all
https://hg.mozilla.org/releases/mozilla-beta/rev/85d1415184ba
status-firefox45: wontfix → unaffected
status-firefox46: affected → disabled
status-firefox47: affected → disabled
status-firefox-esr45: --- → unaffected
5 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-beta: 5

Platform breakdown:
* osx-10-6: 2
* linux64: 2
* android-4-3-armv7-api15: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1237176&startday=2016-03-14&endday=2016-03-20&tree=all
You need to log in before you can comment on or make changes to this bug.