Closed Bug 843479 Opened 11 years ago Closed 11 years ago

Frequent Ubuntu xpcshell failure: test_init_async_multiple_then_sync.js | test failed (with xpcshell return code: 0), see following log

Categories

(Release Engineering :: General, defect)

Product:
Release Engineering
Component:
General
Platform:
All
Linux
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED WORKSFORME

People

(Reporter: philor, Unassigned)

References

Details

(Keywords: intermittent-failure, Whiteboard: [leave open])

Attachments

(1 file)

Additional logs
(deleted), patch
Yoric
: review+
Details | Diff | Splinter Review 
So many moving parts, between switching to Ubuntu and switching to Ubuntu VMs and switching to mozharness, I'm not at all sure where to think this came from.

https://tbpl.mozilla.org/php/getParsedLog.php?id=19932817&tree=Mozilla-Inbound
Ubuntu 12.04 x64 mozilla-inbound opt test xpcshell on 2013-02-20 18:15:43 PST for push 82747d694e7a
slave: tst-linux64-ec2-038

18:44:41     INFO -  TEST-INFO | /builds/slave/test/build/tests/xpcshell/tests/toolkit/components/search/tests/xpcshell/test_init_async_multiple_then_sync.js | running test ...
18:44:42  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/xpcshell/tests/toolkit/components/search/tests/xpcshell/test_init_async_multiple_then_sync.js | test failed (with xpcshell return code: 0), see following log:
18:44:42  WARNING -  This is a harness error.
18:44:42     INFO -  >>>>>>>
18:44:42     INFO -  TEST-INFO | (xpcshell/head.js) | test 1 pending
18:44:42     INFO -  TEST-INFO | /builds/slave/test/build/tests/xpcshell/tests/toolkit/components/search/tests/xpcshell/test_init_async_multiple_then_sync.js | Setting up test
18:44:42     INFO -  TEST-INFO | (xpcshell/head.js) | test 2 pending
18:44:42     INFO -  TEST-INFO | /builds/slave/test/build/tests/xpcshell/tests/toolkit/components/search/tests/xpcshell/test_init_async_multiple_then_sync.js | Test starting
18:44:42     INFO -  *** Search: metadata init: starting
18:44:42     INFO -  *** Search: Search service falling back to synchronous initialization at SRCH_SVC__ensureInitialized@resource://gre/components/nsSearchService.js:2543
18:44:42     INFO -  SRCH_SVC_getEngines@resource://gre/components/nsSearchService.js:3293
18:44:42     INFO -  run_test@/builds/slave/test/build/tests/xpcshell/tests/toolkit/components/search/tests/xpcshell/test_init_async_multiple_then_sync.js:58
18:44:42     INFO -  _execute_test@/builds/slave/test/build/tests/xpcshell/head.js:325
18:44:42     INFO -  @-e:1
18:44:42     INFO -  This is generally the consequence of an add-on using a deprecated search service API.
18:44:42     INFO -  *** Search: metadata syncInit: starting

(many long lines elided, all of them expressing joy and happiness with how well things are going)

18:44:42     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/toolkit/components/search/tests/xpcshell/test_init_async_multiple_then_sync.js | [run_test : 59] [xpconnect wrapped nsISearchEngine],[xpconnect wrapped nsISearchEngine],[xpconnect wrapped nsISearchEngine],[xpconnect wrapped nsISearchEngine],[xpconnect wrapped nsISearchEngine],[xpconnect wrapped nsISearchEngine],[xpconnect wrapped nsISearchEngine] != null
18:44:42     INFO -  TEST-INFO | (xpcshell/head.js) | test 2 finished
18:44:42     INFO -  TEST-INFO | (xpcshell/head.js) | running event loop
18:44:42     INFO -  TEST-INFO | (xpcshell/head.js) | test 1 finished
18:44:42     INFO -  TEST-INFO | (xpcshell/head.js) | exiting test
18:44:42     INFO -  TEST-PASS | (xpcshell/head.js) | 18 (+ 0) check(s) passed
18:44:42     INFO -  TEST-INFO | (xpcshell/head.js) | 0 check(s) todo
18:44:42     INFO -  *** Search: _batchCacheInvalidation: Invalidating engine cache
18:44:42     INFO -  *** Search: _buildCache: Writing to cache file.
18:44:42     INFO -  <<<<<<<

Note that "see following log" is an unhelpful suggestion, because there's absolutely no visible sign of failure anywhere in the log. The only slightly odd looking thing is that "INFO -  @-e:1".

Is mozharness eating a failure? Is mozharness calling success failure? Is something broken with the Ubuntu slaves that's causing this (intermittent, but hellishly frequent) failure?

https://tbpl.mozilla.org/php/getParsedLog.php?id=19936099&tree=Mozilla-Inbound
tst-linux64-ec2-028

https://tbpl.mozilla.org/php/getParsedLog.php?id=19933626&tree=Mozilla-Inbound
tst-linux64-ec2-008

https://tbpl.mozilla.org/php/getParsedLog.php?id=19934627&tree=Mozilla-Inbound
tst-linux64-ec2-046

https://tbpl.mozilla.org/php/getParsedLog.php?id=19935371&tree=Mozilla-Inbound
tst-linux64-ec2-054

https://tbpl.mozilla.org/php/getParsedLog.php?id=19935177&tree=Firefox
tst-linux32-ec2-065
Keywords: intermittent-failure
Also notable:

http://hg.mozilla.org/mozilla-central/rev/43af5bd72395 landed on February 20, the date of this bug.  (Found using hg annotate on the "see following log" line.)
That'd be an awesome fit if it happened between that landing on the 20th and when I backed it out again on the 20th, then started again when that relanded on the 21st, then moved to m-c when that was merged there at 3am today.
(In reply to Aki Sasaki [:aki] from comment #25)
> Also notable:
> 
> http://hg.mozilla.org/mozilla-central/rev/43af5bd72395 landed on February
> 20, the date of this bug.  (Found using hg annotate on the "see following
> log" line.)

Inbound timeline is as follows:

Initial checkin: 2013-02-20 12:47 PST 
Backout:         2013-02-20 17:22 PST 
Final checkin:   2013-02-21 10:31 PST

Comments #4-7 show inbound failures when this was backed out. Comment #2 even shows a failure on Aurora! Bug 771578 is not the problem here.
I was going to say "oh, mozharness unittests aren't turned on in aurora", but looks like the funky ubuntu for-loop might be enabling mozharness unittests on all branches for ubuntu.

What do we want to do here, switch back to Fedora for xpcshell?
The "INFO -  @-e:1" (and surrounding lines) is normal and expected by this test. We are forcing the use of a fallback that causes this warning.
Attached patch Additional logs (deleted) — — Splinter Review 
The attached patch adds more logging to the test, which might help us find out where things fail. Self-reviewing, given that it's only logging.
Attachment #717598 - Flags: review+
Keywords: checkin-needed
Whiteboard: [leave open]
I do not see anything of the logs that I have added in the patch landed by Ryan.

As the links all seem to come from Mozilla-Aurora, does this mean that we should uplift this patch to get any additional logs?
Removing the talos dependency, as xpcshell is not talos.
No longer blocks: 713055
Product: mozilla.org → Release Engineering
Status: NEW → RESOLVED
Closed: 11 years ago
Resolution: --- → WORKSFORME
Component: General Automation → General
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: