Closed Bug 1536583 Opened 6 years ago Closed 2 years ago

Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py <random>.test_history_pushstate | AssertionError: u'http://172.17.0.6:38642/navigation_pushstate.html' != 'http://172.17.0.6:38642/navigation_pushstate_target

Categories

(Testing :: Marionette Client and Harness, defect, P5)

Product:
Testing
Component:
Marionette Client and Harness
Version:
Version 3
Type:
defect

Tracking

(firefox68 affected, firefox69 affected)

Status:
RESOLVED WORKSFORME
Tracking Flags:
Tracking Status
firefox68 --- affected
firefox69 --- affected

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, mobile, Whiteboard: [waiting for 1552742])

#[markdown(off)]
Filed by: apavel [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=234843942&repo=autoland

https://queue.taskcluster.net/v1/task/AUd-sleDTweKGuyPlj3YSg/runs/0/artifacts/public/logs/live_backing.log

[task 2019-03-19T19:27:33.041Z] 19:27:33 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_history_pushstate
[task 2019-03-19T19:27:34.164Z] 19:27:34 WARNING - TEST-UNEXPECTED-FAIL | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_history_pushstate | AssertionError: u'http://172.17.0.6:38642/navigation_pushstate.html' != 'http://172.17.0.6:38642/navigation_pushstate_target.html'
[task 2019-03-19T19:27:34.164Z] 19:27:34 INFO - Traceback (most recent call last):
[task 2019-03-19T19:27:34.164Z] 19:27:34 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run
[task 2019-03-19T19:27:34.164Z] 19:27:34 INFO - testMethod()
[task 2019-03-19T19:27:34.164Z] 19:27:34 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py", line 664, in test_history_pushstate
[task 2019-03-19T19:27:34.164Z] 19:27:34 INFO - self.assertEqual(self.marionette.get_url(), target_page)
[task 2019-03-19T19:27:34.164Z] 19:27:34 INFO - TEST-INFO took 1123ms
[task 2019-03-19T19:27:34.452Z] 19:27:34 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_image
[task 2019-03-19T19:27:34.941Z] 19:27:34 INFO - TEST-PASS | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_image | took 489ms

Should be fixed now by reducing the number of workers for packet.net instances over on bug 1545308.

Assignee: nobody → coop
Status: NEW → RESOLVED
Closed: 6 years ago
status-firefox68: --- → fixed
Depends on: 1545308
Resolution: --- → FIXED
Target Milestone: --- → mozilla68

This is actually not fixed. :/

Assignee: coop → nobody
Status: RESOLVED → REOPENED
status-firefox68: fixed → ---
Resolution: FIXED → ---
Target Milestone: mozilla68 → ---
Summary: Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_history_pushstate | AssertionError: u'http://172.17.0.6:38642/navigation_pushstate.html' != 'http://172.17.0.6:38642/navigation_pushstate_target → Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py <random>.test_history_pushstate | AssertionError: u'http://172.17.0.6:38642/navigation_pushstate.html' != 'http://172.17.0.6:38642/navigation_pushstate_target

This bug failed 50 times in the last 7 days. Occurs on android-em-7-0-x86_64 on opt build types.

Recent log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=245818369&repo=autoland&lineNumber=2415

In the last 7 days, there have been 43 failures.

All the failures affecting android-em-7-0-x86_64 platform, opt build type.

An example of a recent log file:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=247062947&repo=autoland&lineNumber=2449

Henrik, can you please take a look?
Thank you

Flags: needinfo?(hskupin)
Whiteboard: [stockwell needswork]

Here an excerpt from the android logcat:

05-17 16:53:06.223 2366 2383 I Gecko : 1558108386223 Marionette DEBUG 541 -> [0,17,"WebDriver:FindElement",{"using":"id","value":"forward"}]
05-17 16:53:06.225 2366 2383 I Gecko : 1558108386225 Marionette DEBUG 541 <- [1,17,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"9b775c29-e07f-4bde-a471-4dd29999e652"}}]
05-17 16:53:06.228 2366 2383 I Gecko : 1558108386228 Marionette DEBUG 541 -> [0,18,"WebDriver:ElementClick",{"id":"9b775c29-e07f-4bde-a471-4dd29999e652"}]
05-17 16:53:06.730 2366 2366 D GeckoToolbar: onTabChanged: THUMBNAIL
05-17 16:53:06.730 2366 2366 D GeckoBrowserApp: BrowserApp.onTabChanged: 45: THUMBNAIL
05-17 16:53:06.747 2366 2383 I Gecko : 1558108386747 Marionette WARN TimedPromise timed out after 500 ms: stacktrace:
05-17 16:53:06.747 2366 2383 I Gecko : bail@chrome://marionette/content/sync.js:223:64
05-17 16:53:06.957 2366 2383 I Gecko : 1558108386957 Marionette DEBUG [637] Canceled page load listener because no navigation has been detected
05-17 16:53:06.958 2366 2383 I Gecko : 1558108386958 Marionette DEBUG 541 <- [1,18,null,{"value":null}]
05-17 16:53:06.960 2366 2383 I Gecko : 1558108386959 Marionette DEBUG 541 -> [0,19,"WebDriver:GetCurrentURL",{}]
05-17 16:53:06.960 2366 2383 I Gecko : 1558108386960 Marionette DEBUG 541 <- [1,19,null,{"value":"http://172.17.0.5:42592/navigation_pushstate.html"}]

So this needs to be investigated and fixed via bug 1552742.

status-firefox68: --- → affected
Flags: needinfo?(hskupin)
Keywords: mobile

In the last 7 days there have been 54 occurrences on Android 7 Opt.

Whiteboard: [stockwell disable-recommended] → [waiting for 1552742]

There have been 36 occurences on android-em-7-0-x86_64 op in the last 7 days: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-05-29&endday=2019-06-05&tree=trunk&bug=1536583

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=248876074&repo=autoland&lineNumber=2444

[task 2019-05-29T03:10:41.582Z] 03:10:41 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_history_pushstate
[task 2019-05-29T03:10:42.633Z] 03:10:42 WARNING - TEST-UNEXPECTED-FAIL | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_history_pushstate | AssertionError: u'http://172.17.0.6:40730/navigation_pushstate.html' != 'http://172.17.0.6:40730/navigation_pushstate_target.html'
[task 2019-05-29T03:10:42.633Z] 03:10:42 INFO - Traceback (most recent call last):
[task 2019-05-29T03:10:42.634Z] 03:10:42 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run
[task 2019-05-29T03:10:42.634Z] 03:10:42 INFO - testMethod()
[task 2019-05-29T03:10:42.634Z] 03:10:42 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py", line 664, in test_history_pushstate
[task 2019-05-29T03:10:42.634Z] 03:10:42 INFO - self.assertEqual(self.marionette.get_url(), target_page)
[task 2019-05-29T03:10:42.634Z] 03:10:42 INFO - TEST-INFO took 1051ms
[task 2019-05-29T03:10:42.917Z] 03:10:42 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_image

whimboo, any updates on this or Bug 1552742 ?

Flags: needinfo?(hskupin)

The failure stopped on autoland after I pushed my patch on bug 1335085. So I hope that this also fixes that failure. I will keep an eye on it.

It's actually back today, but it looks like the number of failures have been reduced at least.

I will have to take a look at some point later this or next week.

No more failures have been reported since June 7th.

Flags: needinfo?(hskupin)

(In reply to Henrik Skupin (:whimboo) [⌚️UTC+2] from comment #24)

No more failures have been reported since June 7th.

Sorry, I only clicked the link from the last comment of the Intermittent Failures Robot. This is actually still happening a lot. I will see if I can find some time this week to look at it.

Flags: needinfo?(hskupin)

I can replicate this failure pretty easily locally with the x86 Android emulator. I will check now why this happens.

status-firefox69: --- → affected

The problem here is that we interfere with loading about:newtab in Fennec because the default setting isn't taken into account due to bug 1506782. Our test page is sometimes not loaded, and we fail.

It means we need as best a patch on bug 1533058 to get this fixed.

Status: REOPENED → NEW
Depends on: 1533058
Flags: needinfo?(hskupin)

Sadly we cannot fix it with bug 1533058, but have to wait for bug 1506782.

Depends on: 1506782
No longer depends on: 1533058
Status: NEW → RESOLVED
Closed: 6 years ago → 2 years ago
Resolution: --- → WORKSFORME
Product: Testing → Remote Protocol
Moving bug to Testing::Marionette Client and Harness component per bug 1815831.
Component: Marionette → Marionette Client and Harness
Product: Remote Protocol → Testing
You need to log in before you can comment on or make changes to this bug.