Closed Bug 1665210 Opened 2 months ago Closed 2 months ago

Perma Mn-fis testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_navigate_top_frame_from_nested_context | AssertionError: u'about:blank' != 'http://127.0.0.1:50030/test.html'

Categories

(Testing :: Marionette, defect, P5)

defect

Tracking

(Fission Milestone:M7, firefox-esr78 unaffected, firefox81 unaffected, firefox82 disabled, firefox83 fixed)

RESOLVED FIXED
83 Branch
Fission Milestone M7
Tracking Status
firefox-esr78 --- unaffected
firefox81 --- unaffected
firefox82 --- disabled
firefox83 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: whimboo)

References

(Blocks 1 open bug, Regression)

Details

(Keywords: intermittent-failure, regression)

Attachments

(1 file)

Filed by: nbeleuzu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=315780699&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/OO5UT6CEQWGoXo3lzOiwkw/runs/0/artifacts/public/logs/live_backing.log


[task 2020-09-15T21:06:29.572Z] 21:06:29     INFO -  DEBUG: Adding blocker ContentParent: id=26928190000 for phase xpcom-will-shutdown
[task 2020-09-15T21:06:29.572Z] 21:06:29     INFO -  DEBUG: Adding blocker ContentParent: id=26928190000 for phase profile-before-change
[task 2020-09-15T21:06:29.572Z] 21:06:29     INFO -  1600203989563	Marionette	DEBUG	18 <- [1,21,null,{"value":"about:blank"}]
[task 2020-09-15T21:06:29.582Z] 21:06:29     INFO -  [Child 10808, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp, line 348
[task 2020-09-15T21:06:29.582Z] 21:06:29     INFO -  1600203989575	Marionette	DEBUG	18 -> [0,22,"Marionette:GetContext",{}]
[task 2020-09-15T21:06:29.582Z] 21:06:29     INFO -  1600203989576	Marionette	DEBUG	18 <- [1,22,null,{"value":"content"}]
[task 2020-09-15T21:06:29.592Z] 21:06:29     INFO -  1600203989585	Marionette	DEBUG	18 -> [0,23,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-09-15T21:06:29.592Z] 21:06:29     INFO -  1600203989585	Marionette	DEBUG	18 <- [1,23,null,{"value":null}]
[task 2020-09-15T21:06:29.655Z] 21:06:29     INFO -  1600203989652	Marionette	DEBUG	18 -> [0,24,"WebDriver:TakeScreenshot",{"full":true,"hash":false,"id":null,"scroll":true}]
[task 2020-09-15T21:06:29.817Z] 21:06:29     INFO -  1600203989808	Marionette	DEBUG	18 <- [1,24,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABQAAAAQHCAYAAACjlsT7AAAgAElEQVR4nOzdb3Bd5X0ver08c+uZc+950VbnTZn6nEEMcHppb6MpmTbh ... wCIAAAADR8+wB4Op02v9jCmO88AiAAAAA0fMsAON+Wu74V2RjzcwRAAAAAaPiWAdAYc3sEQAAAAGgQAI0xwxEAAQAAoOEfGc0FxdeIhZoAAAAASUVORK5CYII="}]
[task 2020-09-15T21:06:29.836Z] 21:06:29     INFO -  1600203989832	Marionette	DEBUG	18 -> [0,25,"Marionette:SetContext",{"value":"content"}]
[task 2020-09-15T21:06:29.836Z] 21:06:29     INFO -  1600203989833	Marionette	DEBUG	18 <- [1,25,null,{"value":null}]
[task 2020-09-15T21:06:29.836Z] 21:06:29     INFO -  1600203989835	Marionette	DEBUG	18 -> [0,26,"Marionette:GetContext",{}]
[task 2020-09-15T21:06:29.838Z] 21:06:29     INFO -  1600203989835	Marionette	DEBUG	18 <- [1,26,null,{"value":"content"}]
[task 2020-09-15T21:06:29.840Z] 21:06:29     INFO -  1600203989837	Marionette	DEBUG	18 -> [0,27,"Marionette:SetContext",{"value":"content"}]
[task 2020-09-15T21:06:29.840Z] 21:06:29     INFO -  1600203989837	Marionette	DEBUG	18 <- [1,27,null,{"value":null}]
[task 2020-09-15T21:06:29.850Z] 21:06:29     INFO -  1600203989845	Marionette	DEBUG	18 -> [0,28,"WebDriver:GetPageSource",{}]
[task 2020-09-15T21:06:29.850Z] 21:06:29     INFO -  1600203989847	Marionette	DEBUG	18 <- [1,28,null,{"value":"<html><head>\n<title>Marionette Test</title>\n</head>\n<body>\n  <h1 id=\"testh1\">Test Page</h1>\n  <sc ...  <input id=\"createDivButton\" type=\"button\" value=\"create a div\" onclick=\"addDelayedElement()\">\n\n\n</body></html>"}]
[task 2020-09-15T21:06:29.852Z] 21:06:29     INFO -  1600203989849	Marionette	DEBUG	18 -> [0,29,"Marionette:SetContext",{"value":"content"}]
[task 2020-09-15T21:06:29.852Z] 21:06:29     INFO -  1600203989850	Marionette	DEBUG	18 <- [1,29,null,{"value":null}]
[task 2020-09-15T21:06:29.853Z] 21:06:29    ERROR -  TEST-UNEXPECTED-FAIL | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_navigate_top_frame_from_nested_context | AssertionError: u'about:blank' != 'http://127.0.0.1:50030/test.html'
[task 2020-09-15T21:06:29.853Z] 21:06:29     INFO -  Traceback (most recent call last):
[task 2020-09-15T21:06:29.853Z] 21:06:29     INFO -    File "Z:\task_1600203065\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 196, in run
[task 2020-09-15T21:06:29.853Z] 21:06:29     INFO -      testMethod()
[task 2020-09-15T21:06:29.853Z] 21:06:29     INFO -    File "Z:\task_1600203065\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py", line 182, in test_navigate_top_frame_from_nested_context
[task 2020-09-15T21:06:29.853Z] 21:06:29     INFO -      self.assertEqual(self.marionette.get_url(), self.test_page_remote)
[task 2020-09-15T21:06:29.853Z] 21:06:29     INFO -  TEST-INFO took 957ms```

I will have a look what's causing this failure. Probably related to my changes on bug 1493108.

Assignee: nobody → hskupin
Status: NEW → ASSIGNED
Keywords: assertion
Priority: P5 → P1
Whiteboard: [marionette-fission-mvp]
Keywords: regression
Regressed by: 1493108

The problem here is that we cancel the wait for navigation finished too early because there is a remoteness change:

1600232808166	Marionette	DEBUG	2 -> [0,20,"WebDriver:ElementClick",{"id":"1dcb07a4-ea44-f44f-8b1c-5a48b9cc476d"}]
1600232808193	Marionette	TRACE	Received message beforeunload for data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%3Ctitle%3Ebar%3C/title%3E%0A%20%20%20%20%20%20%20%20%20%20%3Ca ... 3D%22http%3A//127.0.0.1%3A57024/test.html%22%20target%3D%22_top%22%3Econsume%20top%20frame%3C/a%3E%0A%20%20%20%20%20%20%20%20
1600232808241	Marionette	TRACE	[36] Frame script unloaded
1600232808242	Marionette	TRACE	[36] Frame with id 8589934593 got removed
1600232808244	Marionette	TRACE	Received message pagehide for data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%3Ctitle%3Ebar%3C/title%3E%0A%20%20%20%20%20%20%20%20%20%20%3Ca ... 3D%22http%3A//127.0.0.1%3A57024/test.html%22%20target%3D%22_top%22%3Econsume%20top%20frame%3C/a%3E%0A%20%20%20%20%20%20%20%20
1600232808244	Marionette	TRACE	Canceled page load listener because current frame has been removed
1600232808244	Marionette	DEBUG	2 <- [1,20,null,{"value":null}]
1600232808251	Marionette	DEBUG	2 -> [0,21,"WebDriver:GetCurrentURL",{}]
1600232808363	Marionette	TRACE	[36] Frame script loaded
1600232808365	Marionette	TRACE	Detected remoteness change. New browsing context: 36

The causing changeset is:
https://hg.mozilla.org/integration/autoland/rev/bcf6908307f71714798acb55a7e8b41e8a2b9bfb

Actually this test was unskipped:
https://hg.mozilla.org/integration/autoland/rev/bcf6908307f71714798acb55a7e8b41e8a2b9bfb#l4.48

I propose that we skip this test for the moment, so we have a bit of time to get it fixed. Note that this only affects Fission.

Summary: Perma [Tier2] testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_navigate_top_frame_from_nested_context | AssertionError: u'about:blank' != 'http://127.0.0.1:50030/test.html' → Perma Mn-fis testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_navigate_top_frame_from_nested_context | AssertionError: u'about:blank' != 'http://127.0.0.1:50030/test.html'

Given that this problem happens with WebDriver:ElementClick we will have to wait until it has been made Fission compatible. Also switching from using navigation events to the webprogress listener might be needed here to detect that we just have a remoteness change.

Depends on: 1660332, 1664165
Assignee: hskupin → nobody
Status: ASSIGNED → NEW
Keywords: leave-open
Priority: P1 → P5
Assignee: nobody → hskupin
Status: NEW → ASSIGNED
Assignee: hskupin → nobody
Status: ASSIGNED → NEW
Pushed by hskupin@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/70f1ab1a4e32
[marionette] Skip TestNavigate.test_navigate_top_frame_from_nested_context for Fission. r=marionette-reviewers,jgraham
Assignee: nobody → hskupin
Status: NEW → ASSIGNED
Assignee: hskupin → nobody
Status: ASSIGNED → NEW

Tentatively tracking marionette-fission-mvp bugs for Fission M7 Beta milestone. We would like Marionette tests to work with Fission before we ride the trains to Beta.

Fission Milestone: --- → M7
Regressions: 1665505
No longer regressions: 1665505
Depends on: 1665489

A fix will be provided via bug 1665489. So we can unskip soon.

Test is fixed and unskipped for Fission now.

Assignee: nobody → hskupin
Status: NEW → RESOLVED
Closed: 2 months ago
No longer depends on: 1660332, 1664165
Keywords: leave-open
Resolution: --- → FIXED
Whiteboard: [marionette-fission-mvp]
Target Milestone: --- → 83 Branch
You need to log in before you can comment on or make changes to this bug.