Closed Bug 1237492 Opened 10 years ago Closed 9 years ago

Intermittent test_jsterm_autocomplete.html | Bailed out with too many properties - got 1500, expected +0, | matches.length is MAX_AUTOCOMPLETIONS - got +0, expected 1500, | Test timed out.

Categories

(DevTools :: Console, defect, P3)

Product:
DevTools
Component:
Console
Type:
defect

Tracking

(firefox45 wontfix, firefox46 wontfix, firefox47 wontfix, firefox48 wontfix, firefox49 fixed, firefox-esr45 fixed, firefox50 fixed)

Status:
RESOLVED FIXED
Milestone:
Firefox 50
Tracking Flags:
Tracking Status
firefox45 --- wontfix
firefox46 --- wontfix
firefox47 --- wontfix
firefox48 --- wontfix
firefox49 --- fixed
firefox-esr45 --- fixed
firefox50 --- fixed

People

(Reporter: philor, Assigned: sjakthol)

Details

(Keywords: intermittent-failure, Whiteboard: [btpp-backlog])

Attachments

(1 file, 1 obsolete file)

Bug 1237492 - Hold a strong reference to the Worker used in webconsole tests.
58 bytes, text/x-review-board-request
ejpbruel
: review+
Details
8 failures total with a few in the last month.
Priority: -- → P3
Whiteboard: [btpp-backlog]
This failure is slightly more frequent. Something around 6 reported per day. But it looks more related to a timeout rather than the "Bailed out with too many properties" wrong assertion. On these two runs, all assertions are correctly evaluated: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=28481337#L14705 https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=28252756#L0-L12928 We can see that this test is the slowest of its serie: Slowest: 6844ms - chrome://mochitests/content/chrome/devtools/shared/webconsole/test/test_jsterm_autocomplete.html From this run: http://archive.mozilla.org/pub/firefox/tinderbox-builds/mozilla-inbound-win32-debug/1464064997/mozilla-inbound_xp_ix-debug_test-mochitest-other-bm119-tests1-windows-build70.txt.gz But still way away from the failure timeout which seems to be around 30s. But it looks like this test is special and should run all the assertions twice. Once in regular page context and another on in a worker context. Which doesn't seem to happen. Seems to be a race around worker code... The issue into debugging this is that it seems to mostly repro on Window XP Debug, which doesn't seem to run mochitest-chrome on try but only on inbound and fx-team?!
Attached patch patch v1 (obsolete) — — Splinter Review
I'm not sure it will fix this intermittent, but this test isn't able to run more than once (--repeat 2 fails). The test fails if there is any other worker registered, i.e. if there is any previous leftover. Also, some errors are not correctly propagated through our code (WorkerClient.attachThread doesn't call aOnResponse when _request("connected") rejects)
Attachment #8755817 - Flags: review?(ejpbruel)
Still fails. Doesn't mean the previous patch isn't useful! But the intermittent may be related to this exception: 11:40:43 INFO - 995 INFO TEST-START | devtools/shared/webconsole/test/test_jsterm_autocomplete.html 11:40:43 INFO - ++DOMWINDOW == 81 (20EDFC00) [pid = 2100] [serial = 81] [outer = 1EA82400] 11:40:46 INFO - EMITTING: emit(connectionchange, opened, [object Object]) from undefined() -> undefined 11:40:47 INFO - EMITTING: emit(newGlobal, [object Object]) from undefined() -> undefined 11:40:47 INFO - --DOCSHELL 13590400 == 17 [pid = 2100] [id = 14] 11:40:48 INFO - DBG-SERVER: error occurred while processing 'evaluateJSAsync: TypeError: invalid 'in' operand result 11:40:48 INFO - Stack: WCA_evalWithDebugger@resource://devtools/server/actors/webconsole.js:1294:1 11:40:48 INFO - WCA_onEvaluateJS@resource://devtools/server/actors/webconsole.js:873:20 11:40:48 INFO - WCA_onEvaluateJSAsync@resource://devtools/server/actors/webconsole.js:843:20 11:40:48 INFO - DSC_onPacket@resource://devtools/server/main.js:1643:15 11:40:48 INFO - WorkerDebuggerTransport.prototype._onMessage@resource://devtools/shared/transport/transport.js:864:13 11:40:48 INFO - xpcInspector.enterNestedEventLoop@resource://devtools/shared/worker/loader.js:457:9 11:40:48 INFO - EventLoop.prototype.enter@resource://devtools/server/actors/script.js:349:5 11:40:48 INFO - ThreadActor<._pushThreadPause@resource://devtools/server/actors/script.js:542:5 11:40:48 INFO - ThreadActor<.onAttach@resource://devtools/server/actors/script.js:657:7 11:40:48 INFO - DSC_onPacket@resource://devtools/server/main.js:1643:15 11:40:48 INFO - WorkerDebuggerTransport.prototype._onMessage@resource://devtools/shared/transport/transport.js:864:13 11:40:48 INFO - EventListener.handleEvent*WorkerDebuggerTransport.prototype.ready@resource://devtools/shared/transport/transport.js:835:11 11:40:48 INFO - DS_onConnection@resource://devtools/server/main.js:1160:5 11:40:48 INFO - DebuggerServer.connectToParent@resource://devtools/server/main.js:713:12 11:40:48 INFO - @resource://devtools/server/worker.js:46:24 11:40:48 INFO - EventListener.handleEvent*@resource://devtools/server/worker.js:41:1 11:40:48 INFO - Line: 1294, column: 1 result = dbgWindow.executeInGlobalWithBindings(aString, bindings, evalOptions); // Attempt to initialize any declarations found in the evaluated string // since they may now be stuck in an "initializing" state due to the // error. Already-initialized bindings will be ignored. if ("throw" in result) { Here, `result` ends up being undefined, or at least not an object. No idea why that would happen. It seems to be related to workers given the stack. In this test we call attachConsoleToWorker which itself calls onAttach which does the console eval. On a regular run, we go through this codepath and `result` is an object here.
Comment on attachment 8755817 [details] [diff] [review] patch v1 Review of attachment 8755817 [details] [diff] [review]: ----------------------------------------------------------------- This is a nice clean up. Thanks Alex.
Attachment #8755817 - Flags: review?(ejpbruel) → review+
Undefined `result` seems to not reproduce with debug statements... Looks like a subtle race. Last try only dumps if we have an undefined `result` and also fail more gracefully in this case. The issue here is that try runs on Windows XP takes a while to run. I can have only one try result per day.
https://hg.mozilla.org/integration/fx-team/rev/93fa879aca59f3b51d600f727338391117dd5462 Bug 1237492 - Fix test_jsterm_autocomplete.html intermittents by connecting to the expected worker actor. r=ejpbruel
Landed the first patch, I'm confused with the few try I ran with additional fixes. It looks like I'm not longer able to reproduce the undefined `result`... So I'm wondering if the first patch end up fixing or at least reducing this intermittent.
Keywords: leave-open
If a reference is not kept, the Worker might be GCd before the test compteles. If that happens, the test times out as it tries to detach a worker that has already been destroyed. The state object is kept around for the duration of the tests so keeping a reference in the state object ensures the worker lifetime matches that of the test. Review commit: https://reviewboard.mozilla.org/r/64780/diff/#index_header See other reviews: https://reviewboard.mozilla.org/r/64780/
Attachment #8771771 - Flags: review?(ejpbruel)
Try: https://treeherder.mozilla.org/#/jobs?repo=try&revision=e2bcb7d02a226d83e18f9451dfb3cb487f30c38b This patch could help with the WinXP debug failures. This shouldn't have any effect on the 'TypeError: invalid in operand' errors that have been grouped to the same bug. To reproduce the issue, you need to add a call to setTimeout() before ending the test. This gives GC time to run causing the teardown to hang on already destroyed worker.
Comment on attachment 8771771 [details] Bug 1237492 - Hold a strong reference to the Worker used in webconsole tests. https://reviewboard.mozilla.org/r/64780/#review62520 Of course, the real problem here is that detaching from a worker that has already been GCd should not be this fragile. But as a short term solution, this is an acceptable fix.
Attachment #8771771 - Flags: review?(ejpbruel) → review+
Keywords: checkin-needed
(In reply to Sami Jaktholm from comment #28) > This shouldn't have any effect on the 'TypeError: invalid in operand' errors > that have been grouped to the same bug. I'm going to take leave-open off this bug. Let's spin ^ off into a different bug instead of trying to fix multiple unrelated issues in one.
status-firefox45: affected → wontfix
status-firefox46: affected → wontfix
status-firefox47: --- → wontfix
status-firefox48: --- → wontfix
status-firefox49: --- → affected
status-firefox50: --- → affected
Keywords: leave-open
Attachment #8755817 - Attachment is obsolete: true
Pushed by ryanvm@gmail.com: https://hg.mozilla.org/integration/fx-team/rev/0cca5d80caa9 Hold a strong reference to the Worker used in webconsole tests. r=ejpbruel
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/0cca5d80caa9
Status: NEW → RESOLVED
Closed: 9 years ago
status-firefox50: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 50
Assignee: nobody → sjakthol
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: