Closed Bug 1275461 Opened 4 years ago Closed 4 years ago

Intermittent test_peerConnection_simulcastOffer.html | Error in test execution: Error: Timed out waiting for frames timeout/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:462:63 ... promise callback*timeout@http://mochi.test:8888/tests/d

Categories

(Core :: WebRTC: Networking, defect, P3)

defect

Tracking

()

RESOLVED FIXED
mozilla51
Tracking Status
firefox49 --- wontfix
firefox50 --- fixed
firefox51 --- fixed

People

(Reporter: philor, Assigned: bwc)

References

Details

(Keywords: intermittent-failure)

Attachments

(2 files, 1 obsolete file)

Priority: -- → P3
This is a pretty frequent failure that started right after bug 1213773 landed. Can you please take a look, Byron?
Blocks: 1213773
Component: WebRTC → WebRTC: Networking
Flags: needinfo?(docfaraday)
So bug 1213373 added a 2 second timeout that wasn't there before. Let me try extending that.
Flags: needinfo?(docfaraday)
Comment on attachment 8779399 [details]
Bug 1275461: Extend a timeout.

https://reviewboard.mozilla.org/r/70388/#review67750

LGTM
Attachment #8779399 - Flags: review?(drno) → review+
Assignee: nobody → docfaraday
https://hg.mozilla.org/mozilla-central/rev/18c9f28cab5b
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla51
That seems to have slowed the failure rate down by a bit, which is very nice.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Slowed some (perhaps by 1/3 or 1/2 on moving average), but still failing too often.  Ideas?
Flags: needinfo?(drno)
Flags: needinfo?(docfaraday)
I'm not sure I fully grasp what this color blinking madness here https://dxr.mozilla.org/mozilla-central/source/dom/media/tests/mochitest/head.js#843 is suppose to accomplish, but sure is missing a test failure in the finally() timeout case. And as soon as I add that both tests which are using this waitForFrames() function fail on my local machine - so there is probably the chance of a snow flake in hell that these work on spot instances ;-)
Flags: needinfo?(drno)
That's supposed to wait for a ~green pixel and then a ~red pixel in the top-left to verify video is getting through.  The canvas is from VideoStreamHelper, which in startCapturingFrames() (right above waitForFrames) starts flipping between green and red every 100ms (10fps).  the wait checks in an ontimeupdate handler for the right color.

color isn't the best thing to use with video codecs as a flag, but with a wide margin for matching it should be ok.

What is the mod you made to fail the test?  What do you get in the output (from info()'s in dom/canvas/test/captureStream_common.js)?
Flags: needinfo?(drno)
You can either carefully watch the mochitest output and you will notice that you only get the TEST-PASS for one of the red and green checks.
Or you can find "the fix" in attachment 8783737 [details].

What is the purpose of changing the color every 100ms?
What is wrong with the previous approach of changing the color once, wait for it on the other side and then do another round?
Flags: needinfo?(drno)
Er, the "finally" is executed when the promise is settled, whether it was resolved or rejected.
Flags: needinfo?(docfaraday)
(In reply to Nils Ohlmeier [:drno] from comment #37)
> You can either carefully watch the mochitest output and you will notice that
> you only get the TEST-PASS for one of the red and green checks.
> Or you can find "the fix" in attachment 8783737 [details].

   Well, that's probably because you're in PC_REMOTE_ENSURE_NO_FRAMES; one of them will pass because it is already that color, but the other will not.

> 
> What is the purpose of changing the color every 100ms?
> What is wrong with the previous approach of changing the color once, wait
> for it on the other side and then do another round?

   It didn't work with simulcast. It seems like you have to wait a bit for the video engine to start encoding frames for all the streams.
(In reply to Byron Campen [:bwc] from comment #38)
> Er, the "finally" is executed when the promise is settled, whether it was
> resolved or rejected.

Sorry, my bad.
Yes you are right that the color blinking madness happens in the ENSURE_NO_FRAMES steps. I guess the most obvious question here is: do we really need a 8 second timeout to figure out that nothing gets rendered, or can we make the timeout for NO_FRAMES shorter then the new default of 8s?

The other observation which worries me a little is this (which is from the videoRenegotiationInactiveAnswer test not the simulcastOffer) - looks like multiple calls to the waitForFrames() can have strange unexpected results (I'm assuming that having two Promises for red returning is not intended):

1048 INFO Run step 134: PC_REMOTE_WAIT_FOR_FRAMES_2
1049 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_videoRenegotiationInactiveAnswer.html | Should have remote video element for pcRemote 
1050 INFO Waiting for video pcRemote_remote_{6cc34502-b7e2-9e40-b977-592768b9a35a} to match [0,255,0,255] - green (pcRemote_remote_{6cc34502-b7e2-9e40-b977-592768b9a35a} should become green)
1051 INFO Waiting for video pcRemote_remote_{6cc34502-b7e2-9e40-b977-592768b9a35a} to match [255,0,0,255] - red (pcRemote_remote_{6cc34502-b7e2-9e40-b977-592768b9a35a} should become red)
1052 INFO TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_videoRenegotiationInactiveAnswer.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts 
1053 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_videoRenegotiationInactiveAnswer.html | pcRemote_remote_{6cc34502-b7e2-9e40-b977-592768b9a35a} pcRemote_remote_{6cc34502-b7e2-9e40-b977-592768b9a35a} should become green 
1054 INFO Drawing color 255,0,0,1
1055 INFO Drawing color 0,255,0,1
1056 INFO Drawing color 255,0,0,1
1057 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_videoRenegotiationInactiveAnswer.html | pcRemote_remote_{6cc34502-b7e2-9e40-b977-592768b9a35a} pcRemote_remote_{6cc34502-b7e2-9e40-b977-592768b9a35a} should become red 
1058 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_videoRenegotiationInactiveAnswer.html | pcRemote_remote_{6cc34502-b7e2-9e40-b977-592768b9a35a} pcRemote_remote_{6cc34502-b7e2-9e40-b977-592768b9a35a} should become red 
1059 INFO TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_videoRenegotiationInactiveAnswer.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts 
1060 INFO Closing peer connections
Attachment #8783737 - Attachment is obsolete: true
I suspect that something is going wrong in webrtc.org land. Trying to figure out how to work around it. As for the multiple red Promises, that may just be a leftover from the NO_FRAMES step (that promise doesn't just go away).
Comment on attachment 8784540 [details] [diff] [review]
Part 2: See if slowing down the color changes helps

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

Maybe the intermittents are due to dropped frames or something... this seems to help.
Attachment #8784540 - Flags: review?(drno)
Comment on attachment 8784540 [details] [diff] [review]
Part 2: See if slowing down the color changes helps

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

LGTM
Attachment #8784540 - Flags: review?(drno) → review+
https://hg.mozilla.org/mozilla-central/rev/0d7718fd6a8b
Status: REOPENED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → FIXED
Depends on: 1298586
You need to log in before you can comment on or make changes to this bug.