Closed Bug 700540 Opened 13 years ago Closed 12 years ago

Intermittent test_jpakeclient.js | Shouldn't have aborted with jpake.error.timeout!

Categories

(Firefox :: Sync, defect)

x86
macOS
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla13

People

(Reporter: philor, Assigned: rnewman)

References

Details

(Keywords: intermittent-failure)

Attachments

(2 files)

https://tbpl.mozilla.org/php/getParsedLog.php?id=7268734&tree=Mozilla-Inbound
Rev3 MacOSX Leopard 10.5.8 mozilla-inbound opt test xpcshell on 2011-11-07 17:59:11 PST for push f70682372656

TEST-INFO | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_jpakeclient.js | running test ...
TEST-UNEXPECTED-FAIL | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_jpakeclient.js | test failed (with xpcshell return code: 0), see following log:
...
TEST-PASS | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_jpakeclient.js | [server_report : 52] 256 == 256
Sync.RESTRequest	DEBUG	POST http://localhost:8080/report 200

TEST-UNEXPECTED-FAIL | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_jpakeclient.js | Shouldn't have aborted with jpake.error.timeout! - See following stack:
JS frame :: /Users/cltbld/talos-slave/test/build/xpcshell/head.js :: do_throw :: line 453
JS frame :: /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_jpakeclient.js :: onAbort :: line 147
JS frame :: resource:///modules/services-sync/jpakeclient.js :: <TOP_LEVEL> :: line 308
JS frame :: resource:///modules/services-sync/jpakeclient.js :: <TOP_LEVEL> :: line 495
JS frame :: resource://services-sync/util.js :: innerBind :: line 1071
JS frame :: resource:///modules/services-sync/rest.js :: onStopRequest :: line 440
Oh, I eagerly await the day when I have time to look at these in depth :/
Argh, this is a timing problem, but the log doesn't include any sort of timestamp at all!

The J-PAKE client is issuing its five checks and aborting before we deliver the payload it's waiting for. The same root cause appears to be causing all of the failures that I've looked at.

I'm going to add some debug code to this, see if I can get useful timestamps.
My hypothesis is simply that the timed event is firing, occurring, and being processed outside the 100ms window that the test allows. Bumping the timer to ~250ms on my machine causes this error.

A thorough version of this test would kick off the delivery on, say, the third poll, rather than using a timer.
Works on my machine :D
Assignee: nobody → rnewman
Status: NEW → ASSIGNED
Attachment #598677 - Flags: review?(gps)
Comment on attachment 598677 [details] [diff] [review]
Proposed patch. v1

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

Nice. I wonder how many other timers we have in the test code causing intermittent failures...

::: services/sync/tests/unit/test_jpakeclient.js
@@ +69,5 @@
> +// Hook for test code.
> +let hooks = {
> +  onGET: function onGET(request) {
> +  }
> +}

Nit: No newline in empty function body.
Attachment #598677 - Flags: review?(gps) → review+
https://hg.mozilla.org/integration/mozilla-inbound/rev/5e49b31996d0
Whiteboard: [orange] → [orange][inbound]
^ on the last push before the fix merged to m-c.
Typical :D
Whiteboard: [orange][inbound] → [orange][inbound][closeme 20120228]
Happy to just close now and reopened if it is starred again, if that works for you?

https://hg.mozilla.org/mozilla-central/rev/5e49b31996d0
Status: ASSIGNED → RESOLVED
Closed: 12 years ago
Resolution: --- → FIXED
Whiteboard: [orange][inbound][closeme 20120228] → [orange][inbound]
Target Milestone: --- → mozilla13
^ fx-team hasn't merged the fix yet.
Le sigh. All of these tests are broken.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Attached patch Part 2. v1Splinter Review
More of the same.
Attachment #604603 - Flags: review?(gps)
Comment on attachment 604603 [details] [diff] [review]
Part 2. v1

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

LGTM.
Attachment #604603 - Flags: review?(gps) → review+
https://hg.mozilla.org/services/services-central/rev/9f1fa0c72aac

And all our s-c changes are test-only, so:

https://hg.mozilla.org/mozilla-central/rev/9f1fa0c72aac
Status: REOPENED → RESOLVED
Closed: 12 years ago12 years ago
Resolution: --- → FIXED
Whiteboard: [orange][inbound] → [orange]
Whiteboard: [orange]
Component: Firefox Sync: Crypto → Sync
Product: Cloud Services → Firefox
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: