Closed Bug 1058087 Opened 6 years ago Closed 6 years ago

Result logged after SimpleTest.finish() with test_animSVGImage2.html

Categories

(Core :: SVG, defect)

All
Linux
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla34
Tracking Status
firefox32 --- wontfix
firefox33 --- fixed
firefox34 --- fixed
firefox-esr24 --- unaffected
firefox-esr31 --- fixed
b2g-v1.4 --- fixed
b2g-v2.0 --- fixed
b2g-v2.1 --- fixed

People

(Reporter: martijn.martijn, Assigned: martijn.martijn)

References

()

Details

(Keywords: intermittent-failure)

Attachments

(1 file, 2 obsolete files)

Now that subresults are not allowed to be logged after SimpleTest.finish(), we see test failures in this test.

https://tbpl.mozilla.org/php/getParsedLog.php?id=46693246&tree=Mozilla-Inbound#error0
14757 INFO TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/image/test/mochitest/test_animSVGImage2.html | myOnStopFrame called - Result logged after SimpleTest.finish()
14758 INFO TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/image/test/mochitest/test_animSVGImage2.html | Animated image looks correct, at call #3 to onStopFrame - Result logged after SimpleTest.finish()
14759 INFO TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/image/test/mochitest/test_animSVGImage2.html | myOnStopFrame called - Result logged after SimpleTest.finish()
14760 INFO TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/image/test/mochitest/test_animSVGImage2.html | Animated image looks correct, at call #4 to onStopFrame - Result logged after SimpleTest.finish()
Yeah, we need to unregister "myOnStopFrame" as a frameComplete listener before we call SimpleTest.finish(), or else we may keep getting notifications.

Alternately, we can just set a flag when we're done, and make myOnStopFrame a no-op if that flag is set.
Blocks: 907503
(In reply to Daniel Holbert [:dholbert] from comment #1)
> Yeah, we need to unregister "myOnStopFrame" as a frameComplete listener
> before we call SimpleTest.finish(), or else we may keep getting
> notifications.

Isn't that what shouldn't be happening here with the removeObserver call?
http://dxr.mozilla.org/mozilla-central/source/image/test/mochitest/test_animSVGImage2.html#84
Oh, you're right -- I missed that because there are several levels of indirection with the observer-registering.

Given that, I suspect these late calls are really coming from this line:
>   setTimeout(function() { myOnStopFrame(0, 0); }, 1000);
http://dxr.mozilla.org/mozilla-central/source/image/test/mochitest/test_animSVGImage2.html#67
jwatt, do you know what's supposed to be happening here? And do you remember why we need a 1-second timeout?  (Is this text expected to take several seconds to run?)
Flags: needinfo?(jwatt)
Attached patch 1058087.diff (obsolete) — Splinter Review
(In reply to Daniel Holbert [:dholbert] from comment #3)
> Given that, I suspect these late calls are really coming from this line:
> >   setTimeout(function() { myOnStopFrame(0, 0); }, 1000);
> http://dxr.mozilla.org/mozilla-central/source/image/test/mochitest/
> test_animSVGImage2.html#67

Yeah, I see this "myOnStopFrame called" test-pass being added every second, so it seems this setTimeout is the culprit.
However, I did add a clearTimeout to see if that would fix it, but it didn't make a difference. It seems as if clearTimeout doesn't work at all?
Attached patch 1058087.diff (obsolete) — Splinter Review
It turns out multiple setTimeout calls were being called, so that's why clearTimeout didn't work as I would exect. This makes sure that only one setTimeout call can be made in this test and that it is cleared when SimpleTest.finish() is called.
Attachment #8478382 - Attachment is obsolete: true
Attachment #8478407 - Flags: review?(jwatt)
Comment on attachment 8478407 [details] [diff] [review]
1058087.diff

Taking a quick look at this per mw22's request:

>Bug 1058087 - Remove timer so so subresults will be logged after SimpleTest.finish()

s/so so/so no/

>-  setTimeout(function() { myOnStopFrame(0, 0); }, 1000);
>+  if (!gTimer)
>+    gTimer = setTimeout(function() { myOnStopFrame(0, 0); }, 1000);

Hmm.  Shouldn't we also set gTimer back to null, after the timeout fires?  Otherwise, we'll only ever get one call to setTimeout here.  (Maybe that's what was intended originally? Not sure.)


I'll more thoroughly review later (and perhaps answer my question ^), if jwatt doesn't get to this first.
Attachment #8478407 - Flags: review?(dholbert)
(In reply to Daniel Holbert [:dholbert] from comment #23)
> Comment on attachment 8478407 [details] [diff] [review]
> >-  setTimeout(function() { myOnStopFrame(0, 0); }, 1000);
> >+  if (!gTimer)
> >+    gTimer = setTimeout(function() { myOnStopFrame(0, 0); }, 1000);
> 
> Hmm.  Shouldn't we also set gTimer back to null, after the timeout fires? 
> Otherwise, we'll only ever get one call to setTimeout here.  (Maybe that's
> what was intended originally? Not sure.)

Hmm, yeah, you might be right. I don't really understand why this setTimeout is there, either. I guess it's better to let jwatt review this, still.
Comment on attachment 8478407 [details] [diff] [review]
1058087.diff

Yeah, I think the idea is we're supposed to keep calling myOnStopFrame (repeatedly) until compareSnapshots succeeds. But, as shown by this bug, we need to keep ourselves from getting multiple setTimeout-spawned myOnStopFrame calls pending at a time.

I think the simplest way to do that would be to add "gTimer = null;" right before "myOnStopFrame(" in the code quoted in comment 23.

That way, gTimer will be non-null IFF we have a setTimeout pending, and null otherwise.

r=me with that, assuming that makes sense to you and also works.
Attachment #8478407 - Flags: review?(dholbert) → review+
Flags: needinfo?(martijn.martijn)
Ok, added the "gTimer = null;" code.
Let's get this in to fix the intermittent failure.
Attachment #8478407 - Attachment is obsolete: true
Attachment #8478407 - Flags: review?(jwatt)
Flags: needinfo?(martijn.martijn)
Keywords: checkin-needed
/me changes platform to All|Linux, since it looks like this has only been an issue on Ubuntu VM 12.04 debug runs (both x64 and non-x64) so far.

Also, this probably should get a Try run of Mochitest-oth on Linux Debug and/or Linux64 Debug before landing with checkin-needed.
Flags: needinfo?(martijn.martijn)
OS: Mac OS X → Linux
Hardware: x86 → All
Flags: needinfo?(martijn.martijn)
Keywords: checkin-needed
Try was green.
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/1c5714615dd7
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla34
Hrm, does that mean it's not fixed or perhaps this was just before the fix went in?
Note the test timestamp in the comment. It was from a push prior to the merge.
Flags: needinfo?(jwatt)
Depends on: 1103652
No longer depends on: 1103652
You need to log in before you can comment on or make changes to this bug.