1736146 - Intermittent [Tier 2] testing/firefox-ui/tests/functional/security/test_ssl_status_after_restart.py TestSSLStatusAfterRestart.test_ssl_status_after_restart | AssertionError: 'invalid' != 'valid'

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

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

---

[task 2021-10-16T10:34:51.347Z] 10:34:51     INFO - TEST-START | testing/firefox-ui/tests/functional/security/test_ssl_status_after_restart.py TestSSLStatusAfterRestart.test_ssl_status_after_restart
[task 2021-10-16T10:34:51.348Z] 10:34:51     INFO -  1634380491347	Marionette	DEBUG	Accepted connection 4 from 127.0.0.1:49393
[task 2021-10-16T10:34:51.348Z] 10:34:51     INFO -  1634380491348	Marionette	DEBUG	4 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-10-16T10:34:51.350Z] 10:34:51     INFO -  1634380491350	Marionette	DEBUG	4 <- [1,1,null,{"sessionId":"b191b859-4bc8-47b3-ac71-2a3a69174bab","capabilities":{"browserName":"firefox","browserVersion":"95.0a ... 6.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2021-10-16T10:34:51.351Z] 10:34:51     INFO -  1634380491351	Marionette	DEBUG	4 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2021-10-16T10:34:51.351Z] 10:34:51     INFO -  1634380491351	Marionette	DEBUG	4 <- [1,2,null,{"value":null}]
[task 2021-10-16T10:34:51.352Z] 10:34:51     INFO -  1634380491352	Marionette	DEBUG	4 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
<...>
[task 2021-10-16T10:34:53.792Z] 10:34:53     INFO -  Child process with id "1013" has been marked as detached because it is no longer in the managed process group. Keeping reference to the process id "1039" which is the new child process.
[task 2021-10-16T10:34:53.816Z] 10:34: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-10-16T10:34:53.816Z] 10:34:53     INFO - - invalid
[task 2021-10-16T10:34:53.816Z] 10:34:53     INFO - ? --
[task 2021-10-16T10:34:53.816Z] 10:34:53     INFO - + valid
[task 2021-10-16T10:34:53.816Z] 10:34:53     INFO - Traceback (most recent call last):
[task 2021-10-16T10:34:53.816Z] 10:34:53     INFO -   File "/opt/worker/tasks/task_163438032293707/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 202, in run
[task 2021-10-16T10:34:53.816Z] 10:34:53     INFO -     testMethod()
[task 2021-10-16T10:34:53.816Z] 10:34:53     INFO -   File "/opt/worker/tasks/task_163438032293707/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-10-16T10:34:53.816Z] 10:34:53     INFO -     self.verify_certificate_status(self.test_url)
[task 2021-10-16T10:34:53.816Z] 10:34:53     INFO -   File "/opt/worker/tasks/task_163438032293707/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-10-16T10:34:53.816Z] 10:34:53     INFO -     self.assertEqual(identity_box.get_attribute("pageproxystate"), "valid")
[task 2021-10-16T10:34:53.816Z] 10:34:53     INFO - TEST-INFO took 2445ms
<...>
[task 2021-10-16T10:34:53.826Z] 10:34:53     INFO - -------
[task 2021-10-16T10:34:53.826Z] 10:34:53     INFO - passed: 3
[task 2021-10-16T10:34:53.826Z] 10:34:53     INFO - failed: 1
[task 2021-10-16T10:34:53.827Z] 10:34:53     INFO - todo: 0
[task 2021-10-16T10:34:53.827Z] 10:34:53     INFO - 
[task 2021-10-16T10:34:53.827Z] 10:34:53     INFO - FAILED TESTS
[task 2021-10-16T10:34:53.827Z] 10:34:53     INFO - -------
[task 2021-10-16T10:34:53.828Z] 10:34:53     INFO - test_ssl_status_after_restart.py test_ssl_status_after_restart.TestSSLStatusAfterRestart.test_ssl_status_after_restart
[task 2021-10-16T10:34:53.828Z] 10:34:53     INFO - SUITE-END | took 100s
[task 2021-10-16T10:34:54.102Z] 10:34:54     INFO -  1634380494101	Marionette	DEBUG	Accepted connection 2 from 127.0.0.1:49416
[task 2021-10-16T10:34:54.102Z] 10:34:54     INFO -  1634380494102	Marionette	DEBUG	2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-10-16T10:34:54.104Z] 10:34:54     INFO -  1634380494104	Marionette	DEBUG	2 <- [1,1,null,{"sessionId":"312ac67a-8a68-4415-8bb2-703f279abaab","capabilities":{"browserName":"firefox","browserVersion":"95.0a ... 6.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2021-10-16T10:34:54.105Z] 10:34:54     INFO -  1634380494105	Marionette	DEBUG	2 -> [0,2,"Marionette:AcceptConnections",{"value":false}]
[task 2021-10-16T10:34:54.105Z] 10:34:54     INFO -  1634380494105	Marionette	INFO	Stopped listening on port 2828
[task 2021-10-16T10:34:54.106Z] 10:34:54     INFO -  1634380494105	Marionette	DEBUG	2 <- [1,2,null,{"value":null}]
[task 2021-10-16T10:34:54.106Z] 10:34:54     INFO -  1634380494105	Marionette	DEBUG	2 -> [0,3,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2021-10-16T10:34:54.130Z] 10:34:54     INFO -  1634380494130	Marionette	TRACE	Received observer notification quit-application
[task 2021-10-16T10:34:54.131Z] 10:34:54     INFO -  1634380494130	Marionette	TRACE	Received observer notification quit-application
[task 2021-10-16T10:34:54.131Z] 10:34:54     INFO -  1634380494130	Marionette	DEBUG	Marionette stopped listening
[task 2021-10-16T10:34:54.134Z] 10:34:54     INFO -  1634380494133	Marionette	DEBUG	2 <- [1,3,null,{"cause":"shutdown","forced":false}]
[task 2021-10-16T10:34:54.157Z] 10:34:54     INFO -  1634380494157	Marionette	DEBUG	Closed connection 2
[task 2021-10-16T10:34:54.241Z] 10:34:54     INFO -  ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-10-16T10:34:54.413Z] 10:34:54     INFO -  [2021-10-16T10:34:54Z ERROR xulstore::persist] removeDocument error: unavailable
[task 2021-10-16T10:34:54.536Z] 10:34:54    ERROR - Return code: 10
[task 2021-10-16T10:34:54.537Z] 10:34:54    ERROR - Got 1 unexpected statuses
[task 2021-10-16T10:34:54.537Z] 10:34:54  WARNING - # TBPL WARNING #
[task 2021-10-16T10:34:54.537Z] 10:34:54  WARNING - setting return code to 1
<...>
[taskcluster 2021-10-16T10:34:54.872Z]    Exit Code: 1
[taskcluster 2021-10-16T10:34:54.872Z]    User Time: 1m9.870455s
[taskcluster 2021-10-16T10:34:54.872Z]  Kernel Time: 14.031399s
[taskcluster 2021-10-16T10:34:54.872Z]    Wall Time: 2m46.079797s
[taskcluster 2021-10-16T10:34:54.872Z]       Result: FAILED
[taskcluster 2021-10-16T10:34:54.872Z] === Task Finished ===
[taskcluster 2021-10-16T10:34:54.872Z] Task Duration: 2m46.084365s

Comment 1

[Intermittent Failures Robot]

16 failures in 3315 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 11
• mozilla-central: 3
• try: 2

Platform and build breakdown:

• macosx1015-64-qr: 10
  • opt: 10
• windows10-64-2004-qr: 1
  • opt: 1
• macosx1015-64-shippable-qr: 4
  • opt: 4
• macosx1015-64-devedition-qr: 1
  • opt: 1

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

Comment 2

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

This requires bug 1736323 to be fixed.

Comment 3

[Intermittent Failures Robot]

19 failures in 638 pushes (0.03 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 6
• mozilla-central: 7
• try: 6

Platform and build breakdown:

• macosx1015-64-qr: 8
  • opt: 6
  • debug: 2
• macosx1015-64-shippable-qr: 6
  • opt: 6
• macosx1015-64-devedition-qr: 3
  • opt: 3
• windows10-64-2004-devedition-qr: 1
  • opt: 1
• windows10-64-2004-mingwclang-qr: 1
  • debug: 1

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

Comment 4

[Intermittent Failures Robot]

65 failures in 3186 pushes (0.02 failures/push) were associated with this bug in the last 7 days.

This is the #8 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 31
• try: 19
• mozilla-central: 15

Platform and build breakdown:

• macosx1015-64-qr: 33
  • opt: 29
  • debug: 4
• macosx1015-64-devedition-qr: 9
  • opt: 9
• macosx1015-64-shippable-qr: 19
  • opt: 19
• windows10-64-2004-devedition-qr: 2
  • opt: 2
• windows10-64-2004-mingwclang-qr: 1
  • debug: 1
• windows10-64-2004-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1736146&startday=2021-10-18&endday=2021-10-24&tree=all

Comment 5

[Iulian Moraru]

Update:
There have been 41 failures within the last 7 days:
• 29 failures on OS X 10.15 WebRender opt
• 9 failures on OS X 10.15 WebRender Shippable opt
• 1 failures on Windows 10 x86 2004 WebRender opt
• 1 failures on Windows 10 x64 2004 WebRender opt
• 1 failures on Windows 10 x64 2004 WebRender Shippable opt
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=356521046&repo=mozilla-central&lineNumber=3548

[task 2021-10-30T23:02:42.575Z] 23:02:42     INFO - TEST-START | testing/firefox-ui/tests/functional/security/test_ssl_status_after_restart.py TestSSLStatusAfterRestart.test_ssl_status_after_restart
[task 2021-10-30T23:02:42.576Z] 23:02:42     INFO -  1635634962576	Marionette	DEBUG	Accepted connection 4 from 127.0.0.1:49456
[task 2021-10-30T23:02:42.576Z] 23:02:42     INFO -  1635634962576	Marionette	DEBUG	4 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-10-30T23:02:42.578Z] 23:02:42     INFO -  1635634962578	Marionette	DEBUG	4 <- [1,1,null,{"sessionId":"ca1384df-71f1-4ef6-bec4-dc29b61fa7be","capabilities":{"browserName":"firefox","browserVersion":"95.0a ... c.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2021-10-30T23:02:42.579Z] 23:02:42     INFO -  1635634962579	Marionette	DEBUG	4 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2021-10-30T23:02:42.579Z] 23:02:42     INFO -  1635634962579	Marionette	DEBUG	4 <- [1,2,null,{"value":null}]
<...>
[task 2021-10-30T23:02:44.652Z] 23:02:44     INFO -  1635634964651	Marionette	DEBUG	1 <- [1,16,null,{"value":null}]
[task 2021-10-30T23:02:44.652Z] 23:02:44     INFO -  Child process with id "4775" has been marked as detached because it is no longer in the managed process group. Keeping reference to the process id "4801" which is the new child process.
[task 2021-10-30T23:02:44.677Z] 23:02:44     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-10-30T23:02:44.677Z] 23:02:44     INFO - - invalid
[task 2021-10-30T23:02:44.677Z] 23:02:44     INFO - ? --
[task 2021-10-30T23:02:44.677Z] 23:02:44     INFO - + valid
[task 2021-10-30T23:02:44.677Z] 23:02:44     INFO - Traceback (most recent call last):
[task 2021-10-30T23:02:44.677Z] 23:02:44     INFO -   File "/opt/worker/tasks/task_163562821163871/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 202, in run
[task 2021-10-30T23:02:44.677Z] 23:02:44     INFO -     testMethod()
[task 2021-10-30T23:02:44.677Z] 23:02:44     INFO -   File "/opt/worker/tasks/task_163562821163871/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-10-30T23:02:44.677Z] 23:02:44     INFO -     self.verify_certificate_status(self.test_url)
[task 2021-10-30T23:02:44.677Z] 23:02:44     INFO -   File "/opt/worker/tasks/task_163562821163871/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-10-30T23:02:44.677Z] 23:02:44     INFO -     self.assertEqual(identity_box.get_attribute("pageproxystate"), "valid")
[task 2021-10-30T23:02:44.677Z] 23:02:44     INFO - TEST-INFO took 2077ms

Comment 6

[Intermittent Failures Robot]

60 failures in 2845 pushes (0.021 failures/push) were associated with this bug in the last 7 days.

This is the #7 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 31
• try: 18
• mozilla-central: 11

Platform and build breakdown:

• macosx1015-64-qr: 29
  • opt: 29
• macosx1015-64-shippable-qr: 19
  • opt: 19
• macosx1015-64-devedition-qr: 8
  • opt: 8
• windows10-64-2004-shippable-qr: 1
  • opt: 1
• windows10-32-2004-qr: 1
  • opt: 1
• windows10-64-2004-qr: 1
  • opt: 1
• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1736146&startday=2021-10-25&endday=2021-10-31&tree=all

Comment 7

[Intermittent Failures Robot]

19 failures in 495 pushes (0.038 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• mozilla-central: 5
• try: 2
• mozilla-beta: 9
• autoland: 3

Platform and build breakdown:

• macosx1015-64-shippable-qr: 8
  • opt: 8
• macosx1015-64-devedition-qr: 5
  • opt: 5
• windows10-64-2004-devedition-qr: 1
  • opt: 1
• macosx1015-64-qr: 3
  • opt: 3
• linux1804-64-asan-qr: 1
  • opt: 1
• windows10-32-2004-shippable-qr: 1
  • opt: 1

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

Comment 8

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

FYI a patch to fix this failure will land soon via bug 1736323.

Comment 9

[Intermittent Failures Robot]

60 failures in 3030 pushes (0.02 failures/push) were associated with this bug in the last 7 days.

This is the #14 most frequent failure this week.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• mozilla-central: 7
• try: 11
• autoland: 5
• mozilla-beta: 37

Platform and build breakdown:

• macosx1015-64-shippable-qr: 28
  • opt: 28
• macosx1015-64-devedition-qr: 22
  • opt: 22
• macosx1015-64-qr: 5
  • opt: 5
• linux1804-64-asan-qr: 1
  • opt: 1
• windows10-64-2004-devedition-qr: 3
  • opt: 3
• windows10-32-2004-shippable-qr: 1
  • opt: 1

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

Comment 11

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

The fix from bug 1736323 got uplifted to beta as:
https://hg.mozilla.org/releases/mozilla-beta/rev/d76cabaec0c1

Comment 12

[Marian-Vasile Laza]

Hi, it seems that it's unresolved with the fix from bug 1736323.
https://treeherder.mozilla.org/jobs?repo=mozilla-beta&group_state=expanded&selectedTaskRun=VXn91KrMRPC3rHnPp6RGKw.0&resultStatus=testfailed%2Cbusted%2Cexception

Comment 13

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

(In reply to Marian-Vasile Laza from comment #12)

Hi, it seems that it's unresolved with the fix from bug 1736323.
https://treeherder.mozilla.org/jobs?repo=mozilla-beta&group_state=expanded&selectedTaskRun=VXn91KrMRPC3rHnPp6RGKw.0&resultStatus=testfailed%2Cbusted%2Cexception

Thanks for letting me know. That's interesting. I reopened bug 1740021, which should be used for classifications from now on.

Comment 14

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 6

Platform and build breakdown:

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

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