1740021 - Intermittent MacOS testing/firefox-ui/tests/functional/security/test_ssl_status_after_restart.py TestSSLStatusAfterRestart.test_ssl_status_after_restart | AssertionError: 'invalid' != 'valid'

Status: RESOLVED INCOMPLETE

(Testing :: Firefox UI Tests, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: archaeopteryx [at] coole-files.de
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=357353343&repo=try
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/RU9-ydNPTtm_17BUACEGjA/runs/0/artifacts/public/logs/live_backing.log

---

[task 2021-11-08T12:28:52.973Z] 12:28:52     INFO -  1636374532973	Marionette	TRACE	All scripts recorded.
[task 2021-11-08T12:28:52.974Z] 12:28:52     INFO -  1636374532973	Marionette	INFO	Listening on port 2828
[task 2021-11-08T12:28:52.975Z] 12:28:52     INFO -  1636374532974	Marionette	DEBUG	Marionette is listening
[task 2021-11-08T12:28:53.042Z] 12:28:53     INFO -  1636374533042	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:49424
[task 2021-11-08T12:28:53.043Z] 12:28:53     INFO -  1636374533042	Marionette	DEBUG	Closed connection 0
[task 2021-11-08T12:28:53.043Z] 12:28:53     INFO -  1636374533042	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:49425
[task 2021-11-08T12:28:53.045Z] 12:28:53     INFO -  1636374533044	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-11-08T12:28:53.048Z] 12:28:53     INFO -  1636374533047	Marionette	DEBUG	1 <- [1,1,null,{"sessionId":"9c0c9f5e-acbc-40e3-8728-dcebbf75bd75","capabilities":{"browserName":"firefox","browserVersion":"96.0" ... s.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2021-11-08T12:28:53.048Z] 12:28:53     INFO -  1636374533048	Marionette	DEBUG	1 -> [0,2,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-11-08T12:28:53.049Z] 12:28:53     INFO -  1636374533048	Marionette	DEBUG	1 <- [1,2,null,{"value":null}]
[task 2021-11-08T12:28:53.049Z] 12:28:53     INFO -  1636374533049	Marionette	DEBUG	1 -> [0,3,"Marionette:GetContext",{}]
[task 2021-11-08T12:28:53.049Z] 12:28:53     INFO -  1636374533049	Marionette	DEBUG	1 <- [1,3,null,{"value":"chrome"}]
[task 2021-11-08T12:28:53.050Z] 12:28:53     INFO -  1636374533049	Marionette	DEBUG	1 -> [0,4,"Marionette:SetContext",{"value":"content"}]
[task 2021-11-08T12:28:53.050Z] 12:28:53     INFO -  1636374533050	Marionette	DEBUG	1 <- [1,4,null,{"value":null}]
[task 2021-11-08T12:28:53.050Z] 12:28:53     INFO -  1636374533050	Marionette	DEBUG	1 -> [0,5,"WebDriver:GetCurrentURL",{}]
[task 2021-11-08T12:28:53.051Z] 12:28:53     INFO -  1636374533050	Marionette	DEBUG	1 <- [1,5,null,{"value":"about:blank"}]
[task 2021-11-08T12:28:53.218Z] 12:28:53     INFO -  1636374533218	Marionette	DEBUG	1 -> [0,6,"WebDriver:GetCurrentURL",{}]
[task 2021-11-08T12:28:53.219Z] 12:28:53     INFO -  1636374533218	Marionette	DEBUG	1 <- [1,6,null,{"value":"https://sha512.badssl.com/"}]
[task 2021-11-08T12:28:53.219Z] 12:28:53     INFO -  1636374533219	Marionette	DEBUG	1 -> [0,7,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-11-08T12:28:53.220Z] 12:28:53     INFO -  1636374533219	Marionette	DEBUG	1 <- [1,7,null,{"value":null}]
[task 2021-11-08T12:28:53.220Z] 12:28:53     INFO -  1636374533220	Marionette	DEBUG	1 -> [0,8,"WebDriver:FindElement",{"value":"identity-box","using":"id"}]
[task 2021-11-08T12:28:53.221Z] 12:28:53     INFO -  1636374533221	Marionette	TRACE	[31] MarionetteCommands actor created for window id 4
[task 2021-11-08T12:28:53.222Z] 12:28:53     INFO -  1636374533222	Marionette	DEBUG	1 <- [1,8,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"cf581856-8c57-4128-8f04-880d7e7d19cb"}}]
[task 2021-11-08T12:28:53.223Z] 12:28:53     INFO -  1636374533223	Marionette	DEBUG	1 -> [0,9,"WebDriver:GetElementAttribute",{"id":"cf581856-8c57-4128-8f04-880d7e7d19cb","name":"pageproxystate"}]
[task 2021-11-08T12:28:53.223Z] 12:28:53     INFO -  1636374533223	Marionette	DEBUG	1 <- [1,9,null,{"value":"invalid"}]
[task 2021-11-08T12:28:53.225Z] 12:28:53     INFO -  1636374533224	Marionette	DEBUG	1 -> [0,10,"Marionette:GetContext",{}]
[task 2021-11-08T12:28:53.225Z] 12:28:53     INFO -  1636374533225	Marionette	DEBUG	1 <- [1,10,null,{"value":"chrome"}]
[task 2021-11-08T12:28:53.230Z] 12:28:53     INFO -  1636374533230	Marionette	DEBUG	1 -> [0,11,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-11-08T12:28:53.230Z] 12:28:53     INFO -  1636374533230	Marionette	DEBUG	1 <- [1,11,null,{"value":null}]
[task 2021-11-08T12:28:53.232Z] 12:28:53     INFO -  1636374533231	Marionette	DEBUG	1 -> [0,12,"WebDriver:TakeScreenshot",{"id":null,"full":true,"hash":false,"scroll":true}]
[task 2021-11-08T12:28:53.277Z] 12:28:53     INFO -  1636374533276	Marionette	DEBUG	1 <- [1,12,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABQAAAAPNCAYAAADWQsenAAAgAElEQVR4XuzdB5xdRb0H8AlJ6L1KE6QTpEiV3qRDaEpHelWUrrQAoQlI ... ECa1RAAFyjnL4Zgf9/AQHw/9/cTyRAgAABAgQIECBAgAABAk0CAmDTtexKYBUCAqBfCwIECBAgQIAAAQIECBAgQOCGBP4TM70GYZSDfrUAAAAASUVORK5CYII="}]
[task 2021-11-08T12:28:53.279Z] 12:28:53     INFO -  1636374533278	Marionette	DEBUG	1 -> [0,13,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-11-08T12:28:53.279Z] 12:28:53     INFO -  1636374533278	Marionette	DEBUG	1 <- [1,13,null,{"value":null}]
[task 2021-11-08T12:28:53.279Z] 12:28:53     INFO -  1636374533279	Marionette	DEBUG	1 -> [0,14,"Marionette:GetContext",{}]
[task 2021-11-08T12:28:53.279Z] 12:28:53     INFO -  1636374533279	Marionette	DEBUG	1 <- [1,14,null,{"value":"chrome"}]
[task 2021-11-08T12:28:53.280Z] 12:28:53     INFO -  1636374533279	Marionette	DEBUG	1 -> [0,15,"Marionette:SetContext",{"value":"content"}]
[task 2021-11-08T12:28:53.280Z] 12:28:53     INFO -  1636374533279	Marionette	DEBUG	1 <- [1,15,null,{"value":null}]
[task 2021-11-08T12:28:53.280Z] 12:28:53     INFO -  1636374533280	Marionette	DEBUG	1 -> [0,16,"WebDriver:GetPageSource",{}]
[task 2021-11-08T12:28:53.283Z] 12:28:53     INFO -  1636374533283	Marionette	TRACE	[33] MarionetteCommands actor created for window id 9
[task 2021-11-08T12:28:53.284Z] 12:28:53     INFO -  1636374533284	Marionette	DEBUG	1 <- [1,16,null,{"value":"<html><head></head><body></body></html>"}]
[task 2021-11-08T12:28:53.285Z] 12:28:53     INFO -  1636374533284	Marionette	DEBUG	1 -> [0,17,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-11-08T12:28:53.285Z] 12:28:53     INFO -  1636374533285	Marionette	DEBUG	1 <- [1,17,null,{"value":null}]
[task 2021-11-08T12:28:53.286Z] 12:28:53     INFO -  Child process with id "1026" has been marked as detached because it is no longer in the managed process group. Keeping reference to the process id "1053" which is the new child process.
[task 2021-11-08T12:28:53.331Z] 12:28:53     INFO - TEST-UNEXPECTED-FAIL | testing/firefox-ui/tests/functional/security/test_ssl_status_after_restart.py TestSSLStatusAfterRestart.test_ssl_status_after_restart | AssertionError: 'invalid' != 'valid'
[task 2021-11-08T12:28:53.331Z] 12:28:53     INFO - - invalid
[task 2021-11-08T12:28:53.331Z] 12:28:53     INFO - ? --
[task 2021-11-08T12:28:53.331Z] 12:28:53     INFO - + valid
[task 2021-11-08T12:28:53.331Z] 12:28:53     INFO - Traceback (most recent call last):
[task 2021-11-08T12:28:53.331Z] 12:28:53     INFO -   File "/opt/worker/tasks/task_163637436070391/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 202, in run
[task 2021-11-08T12:28:53.331Z] 12:28:53     INFO -     testMethod()
[task 2021-11-08T12:28:53.331Z] 12:28:53     INFO -   File "/opt/worker/tasks/task_163637436070391/build/tests/firefox-ui/tests/testing/firefox-ui/tests/functional/security/test_ssl_status_after_restart.py", line 36, in test_ssl_status_after_restart
[task 2021-11-08T12:28:53.331Z] 12:28:53     INFO -     self.verify_certificate_status(self.test_url)
[task 2021-11-08T12:28:53.331Z] 12:28:53     INFO -   File "/opt/worker/tasks/task_163637436070391/build/tests/firefox-ui/tests/testing/firefox-ui/tests/functional/security/test_ssl_status_after_restart.py", line 46, in verify_certificate_status
[task 2021-11-08T12:28:53.331Z] 12:28:53     INFO -     self.assertEqual(identity_box.get_attribute("pageproxystate"), "valid")
[task 2021-11-08T12:28:53.332Z] 12:28:53     INFO - TEST-INFO took 2101ms

Comment 1

[Henrik Skupin [:whimboo][⌚️UTC+2]]

This is similar to bug 1736146 and somewhat regressed. It's probably happening because we had to remove the isInitialDocument check. And here we might run the check against about:blank instead of the HTTP page.

Comment 2

[Julian Descottes [:jdescottes]]

So far all the failures reported here are either:

• on beta (where the patch for Bug 1739008 is not present)
• on try (1 failure, also without the patch for Bug 1739008)

For the try failure you can check the driver.js used in the push: https://hg.mozilla.org/try/file/10e3f5941b8bc37c2b0d7af7a86a3dee253b889d/remote/marionette/driver.js#l466 it still uses waitForNavigationCompleted

So it's probably not regressed by Bug 1739008, will remove the link.

Comment 3

[Henrik Skupin [:whimboo][⌚️UTC+2]]

This is actually a dupe of bug 1736146. All the reported failures are on beta and as bug 1736146 states it's not fixed there yet.

Comment 4

[Henrik Skupin [:whimboo][⌚️UTC+2]]

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

This is actually a dupe of bug 1736146. All the reported failures are on beta and as bug 1736146 states it's not fixed there yet.

Aryx, for your info to not get more bugs filed for this particular issue.

Comment 5

[Henrik Skupin [:whimboo][⌚️UTC+2]]

There seems to be still a problem on beta:
https://treeherder.mozilla.org/jobs?repo=mozilla-beta&group_state=expanded&selectedTaskRun=VXn91KrMRPC3rHnPp6RGKw.0&resultStatus=testfailed%2Cbusted%2Cexception

Lets reopen for tracking further instances.

Comment 6

[Henrik Skupin [:whimboo][⌚️UTC+2]]

I did some re-triggers and it still seems to fail permanently on mozilla-beta whereby it's all fine on mozilla-central.

Comment 7

[Henrik Skupin [:whimboo][⌚️UTC+2]]

It's actually a problem on MacOS only.

Comment 8

[Intermittent Failures Robot]

20 failures in 2723 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1
• mozilla-beta: 19

Platform and build breakdown:

• macosx1015-64-devedition-qr: 13
  • opt: 13
• macosx1015-64-shippable-qr: 7
  • opt: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1740021&startday=2021-11-08&endday=2021-11-14&tree=all

Comment 9

[Intermittent Failures Robot]

7 failures in 3259 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 7

Platform and build breakdown:

• macosx1015-64-devedition-qr: 4
  • opt: 4
• macosx1015-64-shippable-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1740021&startday=2021-11-15&endday=2021-11-21&tree=all

Comment 10

[Intermittent Failures Robot]

12 failures in 2819 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 12

Platform and build breakdown:

• macosx1015-64-shippable-qr: 7
  • opt: 7
• macosx1015-64-devedition-qr: 5
  • opt: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1740021&startday=2021-11-22&endday=2021-11-28&tree=all

Comment 11

[Henrik Skupin [:whimboo][⌚️UTC+2]]

It's still failing on MacOS beta only. I wonder if another default value for a preference causes the divergence to mozilla-central.

Comment 12

[Intermittent Failures Robot]

1 failures in 3170 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-release: 1

Platform and build breakdown:

• macosx1015-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1740021&startday=2021-11-29&endday=2021-12-05&tree=all

Comment 13

[Henrik Skupin [:whimboo][⌚️UTC+2]]

I saw something similar last week while working on bug 1739369. The number here is pretty low now, so lets if that is still actual for next beta tests. Otherwise lets mark it as being blocked by bug 1739369 for further details.

Comment 14

[Intermittent Failures Robot]

3 failures in 3263 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-release: 3

Platform and build breakdown:

• macosx1015-64-shippable-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1740021&startday=2021-12-13&endday=2021-12-19&tree=all

Comment 15

[Henrik Skupin [:whimboo][⌚️UTC+2]]

No more failures since December 16th on mozilla-release. Marking as incomplete for now.