Open Bug 1374133 Opened 7 years ago Updated 2 years ago

Intermittent /html/browsers/windows/browsing-context-names/choose-_blank-003.html | Unable to locate window: 4294967297


(Testing :: web-platform-tests, defect)

Version 3


(firefox56 wontfix, firefox57 disabled, firefox58 disabled)

Tracking Status
firefox56 --- wontfix
firefox57 --- disabled
firefox58 --- disabled


(Reporter: intermittent-bug-filer, Unassigned)



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

32 failures this week:

mostly on linux, some osx- many configurations.

here is a recent linux64 debug failure log:

and related data from the log:
[task 2017-06-23T19:37:14.382772Z] 19:37:14     INFO - TEST-START | /html/browsers/windows/browsing-context-names/choose-_blank-003.html
[task 2017-06-23T19:37:14.561454Z] 19:37:14     INFO - TEST-UNEXPECTED-ERROR | /html/browsers/windows/browsing-context-names/choose-_blank-003.html | Unable to locate window: 4294967297
[task 2017-06-23T19:37:14.562709Z] 19:37:14     INFO - stacktrace:
[task 2017-06-23T19:37:14.562756Z] 19:37:14     INFO - 	WebDriverError@chrome://marionette/content/error.js:222:5
[task 2017-06-23T19:37:14.562821Z] 19:37:14     INFO - 	NoSuchWindowError@chrome://marionette/content/error.js:444:5
[task 2017-06-23T19:37:14.562872Z] 19:37:14     INFO - 	GeckoDriver.prototype.switchToWindow@chrome://marionette/content/driver.js:1440:11
[task 2017-06-23T19:37:14.562905Z] 19:37:14     INFO - 	TaskImpl_run@resource://gre/modules/Task.jsm:331:42
[task 2017-06-23T19:37:14.563262Z] 19:37:14     INFO - 	TaskImpl@resource://gre/modules/Task.jsm:280:3
[task 2017-06-23T19:37:14.563672Z] 19:37:14     INFO - 	asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-06-23T19:37:14.564055Z] 19:37:14     INFO - 	Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-06-23T19:37:14.564352Z] 19:37:14     INFO - 	TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16
[task 2017-06-23T19:37:14.564679Z] 19:37:14     INFO - 	TaskImpl_run@resource://gre/modules/Task.jsm:339:15
[task 2017-06-23T19:37:14.564948Z] 19:37:14     INFO - 	TaskImpl@resource://gre/modules/Task.jsm:280:3
[task 2017-06-23T19:37:14.565222Z] 19:37:14     INFO - 	asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-06-23T19:37:14.565514Z] 19:37:14     INFO - 	Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-06-23T19:37:14.565781Z] 19:37:14     INFO - 	execute@chrome://marionette/content/server.js:510:15
[task 2017-06-23T19:37:14.566042Z] 19:37:14     INFO - 	onPacket@chrome://marionette/content/server.js:481:7
[task 2017-06-23T19:37:14.566385Z] 19:37:14     INFO - 	_onJSONObjectReady/<@chrome://marionette/content/transport.js:480:9
[task 2017-06-23T19:37:14.566582Z] 19:37:14     INFO - TEST-INFO took 178ms
[task 2017-06-23T19:37:14.591257Z] 19:37:14     INFO - PID 3125 | 1498246634586	Marionette	INFO	New connections will no longer be accepted
 2017-06-23T19:37:14.592758Z] 19:37:14     INFO - PID 3125 | [Parent 3125] WARNING: NS_ENSURE_TRUE(weak) failed: file /home/worker/workspace/build/src/dom/base/nsFrameMessageManager.cpp, line 343
[task 2017-06-23T19:37:14.924872Z] 19:37:14     INFO - PID 3125 | [Parent 3125] WARNING: NS_ENSURE_TRUE(weak) failed: file /home/worker/workspace/build/src/dom/base/nsFrameMessageManager.cpp, line 343
[task 2017-06-23T19:37:14.963479Z] 19:37:14     INFO - PID 3125 | 

not much to go from in the log.

looking on github, I see an author (not in bugzilla?), but not a reviewer:

there is no bugzilla component associated with this test, I am not sure what spec this is implementing, we need to figure that out.

in addition, there are 2 other intermittent bugs for this test case, bug 1373511 (many instances as well) and bug 1295436 (old bug no new instances).

:jgraham, can you find the right component for these tests so we can get the proper team to work on these tests?
Flags: needinfo?(james)
Whiteboard: [stockwell needswork]
Pretty sure what's happening here is either a bug in the harness or a bug in marionette. It's failing to close a window that it thinks exists, which suggests that either the window handles changed, or the window got closed by the test before the harness.
So the relevant harness code is:

    def close_old_windows(self, protocol):
        handles = self.marionette.window_handles
        runner_handle = None
            runner_handle = self.runner_handle
        except ValueError:
            # The runner window probably changed id but we can restore it
            # This isn't supposed to happen, but marionette ids are not yet stable
            # We assume that the first handle returned corresponds to the runner,
            # but it hopefully doesn't matter too much if that assumption is
            # wrong since we reload the runner in that tab anyway.
            runner_handle = handles.pop(0)

        for handle in handles:

        if runner_handle != self.runner_handle:

So we try to close all windows except the window we first had open (self.runner_handle), but if that doesn't exist we leave one window open. In either case runner_handle should be a valid window reference at the start of the loop. The fact that it isn't by the end could be that the test is closing that window, but it certainly ought not to be. Or it could be that marionette is changing the window handles for some reason. WHimboo: any ideas? I can add extra logging here of couse.
Flags: needinfo?(james) → needinfo?(hskupin)
I would suggest that you are using a try build to generate a trace log, or do it yourself. It's hard to tell what's wrong here, and a tracelog would give us the information immediately.
Flags: needinfo?(hskupin)
Pushed by
Skip wpt choose-_blank-003.html for intermittent failures; r=me,test-only
Keywords: leave-open
Whiteboard: [stockwell needswork] → [stockwell disabled]
somehow this disappeared!  I need to reland this and I wish that when we deleted this file it was updated in this bug
Pushed by
Skip wpt choose-_blank-003.html for intermittent failures; r=me,test-only
So this test got disabled? How can it still produce test failures?
Flags: needinfo?(jmaher)
I really don't understand why this test is running :(

:jgraham, do you see anything wrong with ?
Flags: needinfo?(jmaher) → needinfo?(james)
Yes, you put .ini in the [] part so it isn't applied since the names don't match.

In any case it might be worth seeing what happens when bug 1373444 is fixed because that will either fix this or at least make the underlying cause more obvious. Since this isn't a top-100 intermittent it doesn't seem too harmful to wait a while.
Flags: needinfo?(james)
thanks for spotting the error!  we will see how this works out after bug 1373444 is fixed.
Depends on: 1373444
(In reply to Joel Maher ( :jmaher) (UTC-5) from comment #24)
> thanks for spotting the error!  we will see how this works out after bug
> 1373444 is fixed.

Joel, the dependency has been fixed now. Can you check if we can re-enable this test?
Flags: needinfo?(jmaher)
we technically do not have this disabled as I did not annotate the .ini file properly- I see many references to this test failing this morning- so it looks as though bug 1373444 didn't fix the issue.

:whimboo, is there another pending fix, or should we disable this?
Flags: needinfo?(jmaher) → needinfo?(hskupin)
It would be nice to have tracing output for Marionette to actually see what's going on but that's not available. So I don't have the time to dig into web-platform-tests, but James has way more expertise and could have a look. Maybe it's somewhat similar to the issue on bug 1373444.
Flags: needinfo?(hskupin) → needinfo?(james)
Whiteboard: [stockwell disabled] → [stockwell unknown]
Whiteboard: [stockwell unknown] → [stockwell needswork]
Pushed by
Disable /html/browsers/windows/browsing-context-names/choose-_blank-003.html for frequent failures. r=me, a=test-only
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Flags: needinfo?(james)
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.