Closed Bug 1232067 Opened 8 years ago Closed 7 years ago

TEST-UNEXPECTED-FAIL | toolkit/components/osfile/tests/xpcshell/*

Categories

(Toolkit Graveyard :: OS.File, defect)

Product:
Toolkit Graveyard
Component:
OS.File
Platform:
Unspecified
macOS
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(firefox48 fixed, firefox49 fixed, thunderbird_esr45+ fixed, firefox50 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla50
Tracking Flags:
Tracking Status
firefox48 --- fixed
firefox49 --- fixed
thunderbird_esr45 + fixed
firefox50 --- fixed

People

(Reporter: aleth, Assigned: aleth)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file, 1 obsolete file)

Ensure the libc free() is used if the a.out free() is not available
4.94 KB, patch
Yoric
: review+
gchang
: approval-mozilla-aurora+
gchang
: approval-mozilla-beta+
Details | Diff | Splinter Review 
OSX only failure (possibly intermittent on Linux debug).

e.g.
TEST-UNEXPECTED-FAIL | toolkit/components/osfile/tests/xpcshell/test_osfile_closed.js | xpcshell return code: 0
 15:24:21     INFO -  TEST-INFO took 465ms
 15:24:21     INFO -  >>>>>>>
 15:24:21     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
 15:24:21     INFO -  (xpcshell/head.js) | test pending (2)
 15:24:21     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (3)
 15:24:21     INFO -  (xpcshell/head.js) | test MAIN run_test finished (3)
 15:24:21     INFO -  running event loop
 15:24:21     INFO -  toolkit/components/osfile/tests/xpcshell/test_osfile_closed.js | Starting test_closed
 15:24:21     INFO -  (xpcshell/head.js) | test test_closed pending (3)
 15:24:21     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (3)
 15:24:21     INFO -  PROCESS | 6617 | OS Controller Posting message {"fun":"SET_DEBUG","args":[true],"id":1}
 15:24:21     INFO -  PROCESS | 6617 | OS Controller Message posted
 15:24:21     INFO -  PROCESS | 6617 | OS Controller Expecting reply
 15:24:21     INFO -  PROCESS | 6617 | OS Controller Posting message {"fun":"getCurrentDirectory","id":2}
 15:24:21     INFO -  PROCESS | 6617 | OS Controller Message posted
 15:24:21     INFO -  PROCESS | 6617 | OS Controller Expecting reply
 15:24:21     INFO -  PROCESS | 6617 | OS Controller Received message from worker {"id":1,"timeStamps":{"entered":1449876261155,"loaded":1449876261186}}
 15:24:21     INFO -  PROCESS | 6617 | OS Controller Received uncaught error from worker Error: couldn't find function symbol in library resource://gre/modules/workers/require.js line 139 > Function 1042
 15:24:21     INFO -  PROCESS | 6617 | OS Controller Got error [object ErrorEvent]
 15:24:21     INFO -  PROCESS | 6617 | OS Controller Error serialized by DOM Error: couldn't find function symbol in library resource://gre/modules/workers/require.js line 139 > Function 1042
 15:24:21     INFO -  Unexpected exception Error: Error: couldn't find function symbol in library at resource://gre/modules/workers/require.js line 139 > Function:1042
 15:24:21     INFO -  postMessage@resource://gre/modules/PromiseWorker.jsm:326:1
 15:24:21     INFO -  this.BasePromiseWorker.prototype.post@resource://gre/modules/PromiseWorker.jsm:263:1
 15:24:21     INFO -  post/<@resource://gre/modules/osfile/osfile_async_front.jsm:429:25
 15:24:21     INFO -  Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:933:23
 15:24:21     INFO -  this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:812:7
 15:24:21     INFO -  Promise*this.PromiseWalker.scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:743:11
 15:24:21     INFO -  this.PromiseWalker.schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:775:7
 15:24:21     INFO -  Promise.prototype.then@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:450:5
 15:24:21     INFO -  _run_next_test@/builds/slave/test/build/tests/xpcshell/head.js:1468:9
 15:24:21     INFO -  do_execute_soon/<.run@/builds/slave/test/build/tests/xpcshell/head.js:660:9
 15:24:21     INFO -  _do_main@/builds/slave/test/build/tests/xpcshell/head.js:208:5
 15:24:21     INFO -  _execute_test@/builds/slave/test/build/tests/xpcshell/head.js:520:5
 15:24:21     INFO -  @-e:1:1
 15:24:21     INFO -  exiting test
similarly

 15:24:22  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/osfile/tests/xpcshell/test_creationDate.js | xpcshell return code: 0
 15:24:22     INFO -  TEST-INFO took 458ms
 15:24:22     INFO -  >>>>>>>
 15:24:22     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
 15:24:22     INFO -  (xpcshell/head.js) | test pending (2)
 15:24:22     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (3)
 15:24:22     INFO -  (xpcshell/head.js) | test MAIN run_test finished (3)
 15:24:22     INFO -  running event loop
 15:24:22     INFO -  toolkit/components/osfile/tests/xpcshell/test_creationDate.js | Starting test_deprecatedCreationDate
 15:24:22     INFO -  (xpcshell/head.js) | test test_deprecatedCreationDate pending (3)
 15:24:22     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (3)
 15:24:22     INFO -  PROCESS | 6619 | OS Controller Posting message {"fun":"SET_DEBUG","args":[true],"id":1}
 15:24:22     INFO -  PROCESS | 6619 | OS Controller Message posted
 15:24:22     INFO -  PROCESS | 6619 | OS Controller Expecting reply
 15:24:22     INFO -  PROCESS | 6619 | OS Controller Posting message {"fun":"getCurrentDirectory","id":2}
 15:24:22     INFO -  PROCESS | 6619 | OS Controller Message posted
 15:24:22     INFO -  PROCESS | 6619 | OS Controller Expecting reply
 15:24:22     INFO -  PROCESS | 6619 | OS Controller Received message from worker {"id":1,"timeStamps":{"entered":1449876262156,"loaded":1449876262187}}
 15:24:22     INFO -  PROCESS | 6619 | OS Controller Received uncaught error from worker Error: couldn't find function symbol in library resource://gre/modules/workers/require.js line 139 > Function 1042
 15:24:22     INFO -  PROCESS | 6619 | OS Controller Got error [object ErrorEvent]
 15:24:22     INFO -  PROCESS | 6619 | OS Controller Error serialized by DOM Error: couldn't find function symbol in library resource://gre/modules/workers/require.js line 139 > Function 1042
 15:24:22     INFO -  Unexpected exception Error: Error: couldn't find function symbol in library at resource://gre/modules/workers/require.js line 139 > Function:1042
 15:24:22     INFO -  postMessage@resource://gre/modules/PromiseWorker.jsm:326:1
 15:24:22     INFO -  this.BasePromiseWorker.prototype.post@resource://gre/modules/PromiseWorker.jsm:263:1
 15:24:22     INFO -  post/<@resource://gre/modules/osfile/osfile_async_front.jsm:429:25
 15:24:22     INFO -  Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:933:23
 15:24:22     INFO -  this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:812:7
 15:24:22     INFO -  Promise*this.PromiseWalker.scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:743:11
 15:24:22     INFO -  this.PromiseWalker.schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:775:7
 15:24:22     INFO -  Promise.prototype.then@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:450:5
 15:24:22     INFO -  _run_next_test@/builds/slave/test/build/tests/xpcshell/head.js:1468:9
 15:24:22     INFO -  do_execute_soon/<.run@/builds/slave/test/build/tests/xpcshell/head.js:660:9
 15:24:22     INFO -  _do_main@/builds/slave/test/build/tests/xpcshell/head.js:208:5
 15:24:22     INFO -  _execute_test@/builds/slave/test/build/tests/xpcshell/head.js:520:5
 15:24:22     INFO -  @-e:1:1
 15:24:22     INFO -  exiting test
Also failures in toolkit/components/places/tests/migration. Looks like all these only happen on Opt builds.

 10:23:04  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/places/tests/migration/test_current_from_downgraded.js | xpcshell return code: 0
 10:23:04     INFO -  TEST-INFO took 422ms
 10:23:04     INFO -  >>>>>>>
 10:23:04     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
 10:23:04     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
 10:23:04     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
 10:23:04     INFO -  running event loop
 10:23:04     INFO -  toolkit/components/places/tests/migration/test_current_from_downgraded.js | Starting setup
 10:23:04     INFO -  (xpcshell/head.js) | test setup pending (2)
 10:23:04     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
 10:23:04     INFO -  Unexpected exception Error: Error: couldn't find function symbol in library at resource://gre/modules/workers/require.js line 139 > Function:1042
 10:23:04     INFO -  postMessage@resource://gre/modules/PromiseWorker.jsm:326:1
 10:23:04     INFO -  this.BasePromiseWorker.prototype.post@resource://gre/modules/PromiseWorker.jsm:263:1
 10:23:04     INFO -  post/<@resource://gre/modules/osfile/osfile_async_front.jsm:429:25
 10:23:04     INFO -  Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:933:23
 10:23:04     INFO -  this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:812:7
 10:23:04     INFO -  Promise*this.PromiseWalker.scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:743:11
 10:23:04     INFO -  this.PromiseWalker.schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:775:7
 10:23:04     INFO -  Promise.prototype.then@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:450:5
 10:23:04     INFO -  this.Scheduler.push@resource://gre/modules/osfile/osfile_async_front.jsm:376:19
 10:23:04     INFO -  post@resource://gre/modules/osfile/osfile_async_front.jsm:408:1
 10:23:04     INFO -  getCurrentDirectory@resource://gre/modules/osfile/osfile_async_front.jsm:886:10
 10:23:04     INFO -  setupPlacesDatabase<@/builds/slave/test/build/tests/xpcshell/tests/toolkit/components/places/tests/migration/head_migration.js:31:26
 10:23:04     INFO -  setup@/builds/slave/test/build/tests/xpcshell/tests/toolkit/components/places/tests/migration/test_current_from_downgraded.js:5:9
 10:23:04     INFO -  _run_next_test@/builds/slave/test/build/tests/xpcshell/head.js:1468:9
 10:23:04     INFO -  do_execute_soon/<.run@/builds/slave/test/build/tests/xpcshell/head.js:660:9
 10:23:04     INFO -  _do_main@/builds/slave/test/build/tests/xpcshell/head.js:208:5
 10:23:04     INFO -  _execute_test@/builds/slave/test/build/tests/xpcshell/head.js:520:5
 10:23:04     INFO -  @-e:1:1
 10:23:04     INFO -  exiting test
Unexpected exception Error: Error: couldn't find function symbol in library at resource://gre/modules/workers/require.js line 139 > Function:1042
postMessage@resource://gre/modules/PromiseWorker.jsm:326:1
this.BasePromiseWorker.prototype.post@resource://gre/modules/PromiseWorker.jsm:263:1
post/<@resource://gre/modules/osfile/osfile_async_front.jsm:429:25 

seems to be common to all of these. This is inside a try/catch, but the error is uncaught...
Same error is mentioned in Bug 1224846 and Bug 1224847.
OS: Unspecified → Mac OS X
Blocks: 1224847, 1224846
It was mentioned on the call today that 
- kent is uncomfortable shipping 45 without a fix
- fallen plans to work on this soon, so NI fallen as reminder
Flags: needinfo?(philipp)
Assignee: nobody → philipp
Fallen, following your discussion with Yoric, are you confident these failures don't mask any real issue? Because if there is no reasonable way forward we should probably disable these tests for TB.
For future reference, these tests (which only seem to fail in opt automation) all pass if one avoids the version of free() defined here:
https://dxr.mozilla.org/mozilla-central/source/toolkit/components/osfile/modules/osfile_unix_back.jsm#272
(In reply to aleth [:aleth] from comment #8)
> For future reference, these tests (which only seem to fail in opt
> automation) all pass if one avoids the version of free() defined here:
> https://dxr.mozilla.org/mozilla-central/source/toolkit/components/osfile/
> modules/osfile_unix_back.jsm#272

To be more precise, the issue is that the library a.out exists and is successfully opened, but does not contain appear to contain a "free" symbol.
(In reply to aleth [:aleth] from comment #9)
> (In reply to aleth [:aleth] from comment #8)
> > For future reference, these tests (which only seem to fail in opt
> > automation) all pass if one avoids the version of free() defined here:
> > https://dxr.mozilla.org/mozilla-central/source/toolkit/components/osfile/
> > modules/osfile_unix_back.jsm#272
> 
> To be more precise, the issue is that the library a.out exists and is
> successfully opened, but does not contain appear to contain a "free" symbol.

Using the a.out version of free() was added in bug 872577.

Glandium, do you have any idea how this issue could arise in c-c opt xpcshell tests, but not when running the same tests with a local opt build (or on m-c)?
Flags: needinfo?(philipp) → needinfo?(mh+mozilla)
(In reply to aleth [:aleth] from comment #9)
> (In reply to aleth [:aleth] from comment #8)
> > For future reference, these tests (which only seem to fail in opt
> > automation) all pass if one avoids the version of free() defined here:
> > https://dxr.mozilla.org/mozilla-central/source/toolkit/components/osfile/
> > modules/osfile_unix_back.jsm#272
> 
> To be more precise, the issue is that the library a.out exists and is
> successfully opened, but does not contain appear to contain a "free" symbol.

Then why are we not falling back to the catch, which is what the code is assuming what should happen?
Flags: needinfo?(mh+mozilla)
(In reply to Mike Hommey [:glandium] from comment #11)
> (In reply to aleth [:aleth] from comment #9)
> > (In reply to aleth [:aleth] from comment #8)
> > > For future reference, these tests (which only seem to fail in opt
> > > automation) all pass if one avoids the version of free() defined here:
> > > https://dxr.mozilla.org/mozilla-central/source/toolkit/components/osfile/
> > > modules/osfile_unix_back.jsm#272
> > 
> > To be more precise, the issue is that the library a.out exists and is
> > successfully opened, but does not contain appear to contain a "free" symbol.
> 
> Then why are we not falling back to the catch, which is what the code is
> assuming what should happen?

Because that only sets up a lazy getter:
http://searchfox.org/mozilla-central/source/toolkit/components/osfile/modules/osfile_shared_allthreads.jsm#1037
(In reply to aleth [:aleth] from comment #12)
> > Then why are we not falling back to the catch, which is what the code is
> > assuming what should happen?
> 
> Because that only sets up a lazy getter:
> http://searchfox.org/mozilla-central/source/toolkit/components/osfile/
> modules/osfile_shared_allthreads.jsm#1037

In case that wasn't clear: the code in the catch doesn't fail, the failure only happens when the getter is actually called.
(In reply to aleth [:aleth] from comment #13)
> (In reply to aleth [:aleth] from comment #12)
> > > Then why are we not falling back to the catch, which is what the code is
> > > assuming what should happen?
> > 
> > Because that only sets up a lazy getter:
> > http://searchfox.org/mozilla-central/source/toolkit/components/osfile/
> > modules/osfile_shared_allthreads.jsm#1037
> 
> In case that wasn't clear: the code in the catch doesn't fail, the failure
> only happens when the getter is actually called.

So, the catch is not doing what it's expected to do... it seems to me that's what needs fixing.
Flags: needinfo?(dteller)
(In reply to Mike Hommey [:glandium] from comment #14)
> So, the catch is not doing what it's expected to do... it seems to me that's
> what needs fixing.

It's possible it needs fixing, but as the same test apparently passes without problems on m-c, it probably shouldn't fail here in the first place. But I am out of ideas for where to go looking for causes.
Ok, so that's definitely a bug in OS.File. I have an idea to solve it, but I'm not sure when I can get it done.
Flags: needinfo?(dteller)
Maybe you can share what you had in mind in case someone else wants to take a look?
Flags: needinfo?(dteller)
Well, it would be easy to tweak `declareLazy` to have it return a `Promise`. Once this is done, we replace the offending (and useless) `try`/`catch` with Promise-based error handling.
Flags: needinfo?(dteller)
status-thunderbird45: affected → ---
Component: General → OS.File
Product: Thunderbird → Toolkit
This defines a version of declareLazy which allows one to specify a fallback library should the getter fail. The problem with using a declareLazy which returns a promise is that that promise would only resolve/reject when the getter is called, and loading the fallback library in the catch chained onto this promise is too late for that first getter call to return the correct symbol. (Unless I misunderstood what you were proposing, of course.)
Attachment #8761394 - Flags: feedback?(dteller)
Assignee: philipp → aleth
Status: NEW → ASSIGNED
Comment on attachment 8761394 [details] [diff] [review]
Ensure the libc free() is used if the a.out free() is not available

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

Ok, that works, too.
Attachment #8761394 - Flags: feedback?(dteller) → feedback+
Attachment #8761394 - Attachment is obsolete: true
Comment on attachment 8761486 [details] [diff] [review]
Ensure the libc free() is used if the a.out free() is not available

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

lgtm, thanks for the patch
Attachment #8761486 - Flags: review?(dteller) → review+
https://hg.mozilla.org/integration/mozilla-inbound/rev/ac39ded2792c5611ead6f0625296cfcef89c83e3
Bug 1232067 - Ensure the libc free() is used if the a.out free() is not available. r=yoric
https://hg.mozilla.org/mozilla-central/rev/ac39ded2792c
Status: ASSIGNED → RESOLVED
Closed: 7 years ago
status-firefox50: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla50
Fantastic, thx a lot aleth!
Thanks a lot, xpcshell tests on Mac look a lot less red now ;-)
Comment on attachment 8761486 [details] [diff] [review]
Ensure the libc free() is used if the a.out free() is not available

Approval Request Comment
[Feature/regressing bug #]: On affected platforms (where the a.out library doesn't exist or doesn't contain free()), the free() declaration used by OS.File no longer fails.
[User impact if declined]: Leaks and potential errors when getting the current working dir using OS.File
[Describe test coverage new/current, TreeHerder]: Fixes a whole lot of test failures on OS X Opt comm-*
[Risks and why]: low (only affects the code path on affected platforms, no change where things were previously working)
[String/UUID change made/needed]: none
Attachment #8761486 - Flags: approval-mozilla-beta?
Attachment #8761486 - Flags: approval-mozilla-aurora?
Comment on attachment 8761486 [details] [diff] [review]
Ensure the libc free() is used if the a.out free() is not available

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

This fixes test failures and potential leaks. Take it in beta and aurora.
Attachment #8761486 - Flags: approval-mozilla-beta?
Attachment #8761486 - Flags: approval-mozilla-beta+
Attachment #8761486 - Flags: approval-mozilla-aurora?
Attachment #8761486 - Flags: approval-mozilla-aurora+
This did not make Thunderbird beta 47, will be in Thunderbird beta 48, so we will wait until 45.3 to push to release.
Pushed to mozilla-esr45 THUNDERBIRD_45_VERBRANCH
https://hg.mozilla.org/releases/mozilla-esr45/rev/51dd4d5ecb90
Product: Toolkit → Toolkit Graveyard
You need to log in before you can comment on or make changes to this bug.