Closed Bug 1076231 Opened 8 years ago Closed 8 years ago

[SimPicker] fix racy unit tests

Categories

(Firefox OS Graveyard :: Gaia, defect)

defect
Not set
normal

Tracking

(b2g-v2.2 fixed)

RESOLVED FIXED
2.1 S6 (10oct)
Tracking Status
b2g-v2.2 --- fixed

People

(Reporter: julienw, Assigned: drs)

References

Details

Attachments

(1 file, 1 obsolete file)

This is especially visible with the new mocha, see https://tbpl.mozilla.org/php/getParsedLog.php?id=49297827&tree=Gaia-Try#error7

05:50:14     INFO -  TEST-UNEXPECTED-FAIL | sharedtest/test/unit/elements/gaia_sim_picker/gaia_sim_picker_test.js | GaiaSimPicker getOrPick/getInUseSim should show the menu - expected show to be called once but was called 0 times
05:50:14     INFO -      Error: expected show to be called once but was called 0 times
05:50:14     INFO -          at fail (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:4712:25)
05:50:14     INFO -          at failAssertion (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:4673:9)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:4696:17)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/test/unit/elements/gaia_sim_picker/gaia_sim_picker_test.js:110:7)
05:50:14     INFO -          at wrapper (app://sharedtest.gaiamobile.org/common/test/mocha_generators.js:62:19)
05:50:14     INFO -          at run (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4311:7)
05:50:14     INFO -          at runTest (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4728:5)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4806:7)
05:50:14     INFO -          at next (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4653:1)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4663:7)
05:50:14     INFO -          at next (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4601:1)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4630:5)
05:50:14     INFO -          at timeslice (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:5763:5)
05:50:14     INFO -  TEST-UNEXPECTED-FAIL | sharedtest/test/unit/elements/gaia_sim_picker/gaia_sim_picker_test.js | GaiaSimPicker callbacks and functions should fire all queued up callbacks on SIM 0 - Error: expected focus to be called once but was called 0 times (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js?time=1412167814230:4712)
05:50:14     INFO -      Error: Error: expected focus to be called once but was called 0 times (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js?time=1412167814230:4712)
05:50:14     INFO -          at onerror (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:5738:10)
05:50:14     INFO -  TEST-UNEXPECTED-FAIL | sharedtest/test/unit/elements/gaia_sim_picker/gaia_sim_picker_test.js | GaiaSimPicker "before each" hook: wrapper - Attempted to wrap show which is already spied on
05:50:14     INFO -      TypeError: Attempted to wrap show which is already spied on
05:50:14     INFO -          at wrapMethod (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:698:25)
05:50:14     INFO -          at spy (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:1483:16)
05:50:14     INFO -          at spy (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:2877:29)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/test/unit/elements/gaia_sim_picker/gaia_sim_picker_test.js:51:5)
05:50:14     INFO -          at wrapper (app://sharedtest.gaiamobile.org/common/test/mocha_generators.js:62:19)
05:50:14     INFO -          at run (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4311:7)
05:50:14     INFO -          at next (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4613:5)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4625:7)
05:50:14     INFO -          at done (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4300:5)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4314:9)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/test/mocha_generators.js:46:20)
05:50:14     INFO -          at wrapper (app://sharedtest.gaiamobile.org/common/test/mocha_generators.js:73:15)
05:50:14     INFO -          at run (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4311:7)
05:50:14     INFO -          at next (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4613:5)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4630:5)
05:50:14     INFO -          at timeslice (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:5763:5)
05:50:14     INFO -          at wrapMethod (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:715:30)
05:50:14     INFO -          at spy (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:1483:16)
05:50:14     INFO -          at spy (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:2877:29)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/test/unit/elements/gaia_sim_picker/gaia_sim_picker_test.js:51:5)
05:50:14     INFO -          at wrapper (app://sharedtest.gaiamobile.org/common/test/mocha_generators.js:62:19)
05:50:14     INFO -          at run (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4311:7)
05:50:14     INFO -          at next (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4613:5)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4625:7)
05:50:14     INFO -          at done (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4300:5)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4314:9)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/test/mocha_generators.js:46:20)
05:50:14     INFO -          at wrapper (app://sharedtest.gaiamobile.org/common/test/mocha_generators.js:73:15)
05:50:14     INFO -          at run (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4311:7)
05:50:14     INFO -          at next (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4613:5)
05:50:14     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4630:5)
05:50:14     INFO -          at timeslice (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:5763:5)
05:50:14     INFO -  TEST-PASS | sharedtest/test/unit/elements/gaia_sim_picker/gaia_sim_picker_test.js | GaiaSimPicker callbacks and functions should dispatch DOM event when SIM 1 is selected
05:50:15     INFO -  TEST-UNEXPECTED-FAIL | sharedtest/test/unit/elements/gaia_sim_picker/gaia_sim_picker_test.js | GaiaSimPicker "before each" hook: wrapper - Attempted to wrap show which is already spied on
05:50:15     INFO -      TypeError: Attempted to wrap show which is already spied on
05:50:15     INFO -          at wrapMethod (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:698:25)
05:50:15     INFO -          at spy (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:1483:16)
05:50:15     INFO -          at spy (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:2877:29)
05:50:15     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/test/unit/elements/gaia_sim_picker/gaia_sim_picker_test.js:51:5)
05:50:15     INFO -          at wrapper (app://sharedtest.gaiamobile.org/common/test/mocha_generators.js:62:19)
05:50:15     INFO -          at run (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4311:7)
05:50:15     INFO -          at next (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4613:5)
05:50:15     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4625:7)
05:50:15     INFO -          at done (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4300:5)
05:50:15     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4314:9)
05:50:15     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/test/mocha_generators.js:46:20)
05:50:15     INFO -          at wrapper (app://sharedtest.gaiamobile.org/common/test/mocha_generators.js:73:15)
05:50:15     INFO -          at run (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4311:7)
05:50:15     INFO -          at next (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4613:5)
05:50:15     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4630:5)
05:50:15     INFO -          at timeslice (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:5763:5)
05:50:15     INFO -          at wrapMethod (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:715:30)
05:50:15     INFO -          at spy (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:1483:16)
05:50:15     INFO -          at spy (app://sharedtest.gaiamobile.org/common/vendor/sinon/sinon.js:2877:29)
05:50:15     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/test/unit/elements/gaia_sim_picker/gaia_sim_picker_test.js:51:5)
05:50:15     INFO -          at wrapper (app://sharedtest.gaiamobile.org/common/test/mocha_generators.js:62:19)
05:50:15     INFO -          at run (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4311:7)
05:50:15     INFO -          at next (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4613:5)
05:50:15     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4625:7)
05:50:15     INFO -          at done (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4300:5)
05:50:15     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4314:9)
05:50:15     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/test/mocha_generators.js:46:20)
05:50:15     INFO -          at wrapper (app://sharedtest.gaiamobile.org/common/test/mocha_generators.js:73:15)
05:50:15     INFO -          at run (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4311:7)
05:50:15     INFO -          at next (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4613:5)
05:50:15     INFO -          at (anonymous) (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:4630:5)
05:50:15     INFO -          at timeslice (app://sharedtest.gaiamobile.org/common/vendor/mocha/mocha.js:5763:5)
Attached file github PR
hey Doug,

the setup was quite racy because of timeouts in the l10n mock, therefore I added sinon's fake timers to make it predictable.

I also changed some tests, I'll comment more on the PR about this.

Hey David, I feedback you on this patch in case you want to chime in. Doug did the whole file so that's why I asked him a review, but feel free to change if you think this is inappropriate.

Hey Rik, Kevin, I feedback you on this too because you were the original reviewers for this, so feel free to have a look.


Please land if ready, as I'll be away for some days.
Attachment #8498473 - Flags: review?(drs+bugzilla)
Attachment #8498473 - Flags: feedback?(kgrandon)
Attachment #8498473 - Flags: feedback?(dflanagan)
Attachment #8498473 - Flags: feedback?(anthony)
Comment on attachment 8498473 [details] [review]
github PR

I don't think this is a good way to fix this as it requires making changes for every test. We should really isolate the timing logic to the tests that need it.

I would instead suggest stubbing the GaiaSimPicker.focus() and GaiaMenu.show() functions, and calling done() from inside those stubs.

Since you're going on PTO, I'll do this myself.
Attachment #8498473 - Flags: review?(drs+bugzilla) → review-
Flags: needinfo?(drs+bugzilla)
PR: https://github.com/mozilla-b2g/gaia/pull/24638

Including original feedbacks, though I'm not sure they're necessary.
Assignee: felash → drs+bugzilla
Attachment #8498473 - Attachment is obsolete: true
Status: NEW → ASSIGNED
Attachment #8498473 - Flags: feedback?(kgrandon)
Attachment #8498473 - Flags: feedback?(dflanagan)
Attachment #8498473 - Flags: feedback?(anthony)
Attachment #8498571 - Flags: review?(anthony)
Attachment #8498571 - Flags: feedback?(kgrandon)
Attachment #8498571 - Flags: feedback?(dflanagan)
Flags: needinfo?(drs+bugzilla)
Comment on attachment 8498571 [details] [diff] [review]
Fix racy unit tests in GaiaSimPicker.

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

Cool - I wasn't aware of that stub syntax. I guess you could also just pass in done as an argument? Looks good to me!
Attachment #8498571 - Flags: feedback?(kgrandon) → feedback+
Attachment #8498571 - Flags: review?(anthony) → review+
https://github.com/mozilla-b2g/gaia/commit/cae97be548be0cff2f23125c782eb06648e50a4f
Status: ASSIGNED → RESOLVED
Closed: 8 years ago
OS: Linux → All
Hardware: x86_64 → All
Resolution: --- → FIXED
Target Milestone: --- → 2.1 S6 (10oct)
Attachment #8498571 - Flags: feedback?(dflanagan)
FTR I don't really like this style (using "done" in a stub function) because it's more difficult to debug if there is an issue: you'll get a timeout instead of a proper error.

I'm also not sure about the issue I outlined in your setup: getOrPick is called, mockL10n is using a timeout, and you're not waiting for this timeout in setup. Did you check this works as expected with the newer mocha (which was the initial goal of this patch) ?

(In reply to Kevin Grandon :kgrandon from comment #4)

> Cool - I wasn't aware of that stub syntax. I guess you could also just pass
> in done as an argument? Looks good to me!

Be careful with this: if "done" gets an argument, mocha thinks this is a failure. So it's always safer to either use "done.bind(null, null)" or "() => done()".

(In reply to Doug Sherk (:drs) from comment #2)
> Comment on attachment 8498473 [details] [review]
> github PR
> 
> I don't think this is a good way to fix this as it requires making changes
> for every test.

IMO this is the price to pay to get predictable, fast, easy-to-debug tests.

Note that I didn't need to make change for every test in my PR... simply because not all tests need the mozL10n timeout.
My understanding was that the new mocha had landed, and the issue described in comment 0 was an intermittent failure that we were now experiencing. Julien corrected me and showed me how to use the new mocha. Based on comment 6, I tested whether or not my changes fix the issue, and they don't. So when the tree reopens, I'm going to back myself out and resurrect Julien's patch.
Attachment #8498473 - Flags: review- → review+
backed out: https://github.com/mozilla-b2g/gaia/commit/b37e4150a31b395d442464195c7cf4845eff3477
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Comment on attachment 8498473 [details] [review]
github PR

https://github.com/mozilla-b2g/gaia/commit/9e18530027571e9a4361b2283f59d8f6824c206e

(wish I could set checkin+ on the PR)
Attachment #8498473 - Attachment is obsolete: false
Attachment #8498571 - Attachment is obsolete: true
See comment 9.
Status: REOPENED → RESOLVED
Closed: 8 years ago8 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.