Closed Bug 668471 Opened 13 years ago Closed 12 years ago

Intermittent TEST-UNEXPECTED-FAIL | unknown test url | [SimpleTest/SimpleTest.js, window.onerror] - An error occurred: SpecialPowers is not defined at http://mochi.test:8888/tests/Harness_sanity/file_SpecialPowersFrame1.html:10

Categories

(Testing :: Mochitest, defect)

defect
Not set
normal

Tracking

(Not tracked)

RESOLVED WORKSFORME

People

(Reporter: mak, Unassigned)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1309393394.1309396676.30175.gz

SPECIALPTEST2:::Loading test2 file now 1309393763190
before 610304, after 610304, break 00000000
13 INFO TEST-PASS | /tests/Harness_sanity/test_SpecialPowersExtension2.html | Special Powers top level - "foo" should equal "foo"
pldhash: for the table at address 0E574B90, the given entrySize of 48 probably favors chaining over double hashing.
++DOCSHELL 0E574B28 == 7
++DOMWINDOW == 15 (0F046E48) [serial = 17] [outer = 00000000]
++DOMWINDOW == 16 (0F0471F8) [serial = 18] [outer = 0F046DF8]
TEST-UNEXPECTED-FAIL |  | [SimpleTest/SimpleTest.js, window.onerror] - An error occurred: SpecialPowers is not defined at http://mochi.test:8888/tests/Harness_sanity/file_SpecialPowersFrame1.html:11
JavaScript error: http://mochi.test:8888/tests/Harness_sanity/file_SpecialPowersFrame1.html, line 11: SpecialPowers is not defined
14 INFO TEST-END | /tests/Harness_sanity/test_SpecialPowersExtension2.html | finished in 2562ms
That's, uh, really bad.
Is it possible something was checked in for specialpowers that caused it to have a syntax error?
Can (In reply to comment #2)
> Is it possible something was checked in for specialpowers that caused it to
> have a syntax error?

No. First off, this would be a perma-orange and not intermittent. Second, if you look at the logs, the test_SpecialPowersExtension.html sanity checks pass, it's the test_SpecialPowersExtension2.html tests that fail (testing SpecialPowers in a frame).

Something is broken, we need to figure out when this actually started happening. The failure from comment 0 was on http://hg.mozilla.org/mozilla-central/rev/29bc151be813 which doesn't look like it has anything to do with this, so I started looking at changesets prior to that:
http://hg.mozilla.org/mozilla-central/pushloghtml?startdate=2011-07-03&enddate=2011-07-04+05%3A33%3A08

There's one change to specialpowers.js in there, but it looks harmless:
http://hg.mozilla.org/mozilla-central/rev/7a747adc8303

I don't see anything else in that range that's particularly suspicious. It's possible whatever caused this landed even earlier. I need a statistics person to tell me what range we ought to be looking in given the frequency of failure here.
> I don't see anything else in that range that's particularly suspicious. It's 
> possible whatever caused this landed even earlier. I need a statistics person 
> to tell me what range we ought to be looking in given the frequency of failure 
> here.

I need to assume that the chance of seeing this orange on any given push is constant.  This assumption could be wrong if we originally broke this test and then later checked something in which tickled the broken test.  It's possible that the orange was originally so unlikely, we'd never seen it until it was tickled.

I think we can best estimate the probability of failure by looking at the failures which we know occurred after the orange existed, so that gives us 5 failures out of all the pushes after comment 0 (d452aaf438f1).

There were 77 pushes to mozilla-inbound and 51 pushes to mozilla-central since d452aaf, for a total of 128.  We want a lower bound on the failure probability, so let's assume that all of these had successful Windows builds.

Thus the probability of failure is at least 5 / 128 = .039.  Call this F.

So now we ask: Given probability P, find N such that the chance of seeing N test runs in a row with no failure is P.

The chance of seeing N successful runs in a row is (1 - F) ^ N.  So say

  (1 - F) ^ N = P

and solve for N:

  N = (log P) / (log (1 - F))

Now plug in our desired P and known F:

  P = 5%   -->  N = 75
  P = 1%   -->  N = 116
  P = 0.1% -->  N = 173

So you have a 95% chance that the offending changeset occurred 75 pushes before comment 0, a 99% chance that it occurred 116 pushes before, and a 99.9% chance it occurred 173 pushes before.  Again, assuming that the chance of failure has remained constant.

(Note that "N pushes before" counts test runs on both m-c and m-i.)
Attached image Screenshot
Sorry if this is not related to this error, but I noticed something weird.
While running this mochitest from Fennec, it gets reported as passed, but the iframe is red and shows failed:
http://mochi.test:8888/tests/Harness_sanity/test_SpecialPowersExtension2.html

I see this happening all the time.
Maybe that is related to this error?
(In reply to comment #14)
> Created attachment 544526 [details]
> Screenshot
> 
> Sorry if this is not related to this error, but I noticed something weird.
> While running this mochitest from Fennec, it gets reported as passed, but
> the iframe is red and shows failed:
> http://mochi.test:8888/tests/Harness_sanity/test_SpecialPowersExtension2.html
> 
> I see this happening all the time.
> Maybe that is related to this error?

Note that all of these logs have this at the end:

103456 INFO TEST-START | Shutdown
103457 INFO Passed: 100820
103458 INFO Failed: 0
103459 INFO Todo:   886
103460 INFO SimpleTest FINISHED
103461 INFO TEST-INFO | Ran 0 Loops

So, this is never reported as a failure by the suite.
bug 673569 is almost certainly the root cause here. The symptoms described there fit very well, and the pushlog time is damning:
http://hg.mozilla.org/mozilla-central/pushloghtml?changeset=beceddeee3f4

(The other content script that's causing the race with specialpowers.js was pushed on June 30th, exactly when this bug was filed.)
Depends on: 673569
Summary: Intermittent failure - An error occurred: SpecialPowers is not defined at http://mochi.test:8888/tests/Harness_sanity/file_SpecialPowersFrame1.html:11 → Intermittent TEST-UNEXPECTED-FAIL | unknown test url | [SimpleTest/SimpleTest.js, window.onerror] - An error occurred: SpecialPowers is not defined at http://mochi.test:8888/tests/Harness_sanity/file_SpecialPowersFrame1.html:10
Mass marking whiteboard:[orange] bugs WFM (to clean up TBPL bug suggestions) that:
* Haven't changed in > 6months
* Whose whiteboard contains none of the strings: {disabled,marked,random,fuzzy,todo,fails,failing,annotated,leave open,time-bomb}
* Passed a (quick) manual inspection of bug summary/whiteboard to ensure they weren't a false positive.

I've also gone through and searched for cases where the whiteboard wasn't labelled correctly after test disabling, by using attachment description & basic comment searches. However if the test for which this bug was about has in fact been disabled/annotated/..., please accept my apologies & reopen/mark the whiteboard appropriately so this doesn't get re-closed in the future (and please ping me via IRC or email so I can try to tweak the saved searches to avoid more edge cases).

Sorry for the spam! Filter on: #FFA500
Status: NEW → RESOLVED
Closed: 12 years ago
Resolution: --- → WORKSFORME
Whiteboard: [orange]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: