1517377 - Intermittent Windows ccov Tier 2 testing\firefox-ui\tests\functional\sessionstore\test_restore_windows_after_windows_shutdown.py TestWindowsShutdownForcedSessionRestore.test_manual_restart | IOError: Process still running 70s after quit request

Status: RESOLVED FIXED

(Firefox :: General, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: btara [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=219685519&repo=mozilla-central

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

00:36:29     INFO -  ERROR: GC found live SharedScriptData 0000017C84CE21F0 with ref count 2 at shutdown
00:36:29     INFO -  ERROR: GC found live SharedScriptData 0000017C83DEDBA0 with ref count 4 at shutdown
00:36:29     INFO -  ERROR: GC found live SharedScriptData 0000017CFF0C0000 with ref count 2 at shutdown
00:36:29     INFO -  ERROR: GC found live SharedScriptData 0000017C84F26340 with ref count 7 at shutdown
00:36:29     INFO -  Assertion failure: m_refCount == 1, at z:/build/build/src/js/src/jit/ExecutableAllocator.cpp:49
00:36:29     INFO -  Leaked URLs:
00:36:29     INFO -    http://127.0.0.1:50190/layout/mozilla_community.html
00:36:29     INFO -  nsStringStats
00:36:29     INFO -   => mAllocCount:          10272
00:36:29     INFO -   => mReallocCount:            0
00:36:29     INFO -   => mFreeCount:            8736  --  LEAKED 1536 !!!
00:36:29     INFO -   => mShareCount:           7776
00:36:29     INFO -   => mAdoptCount:            557
00:36:29     INFO -   => mAdoptFreeCount:        561
00:36:29     INFO -   => Process ID: 6204, Thread ID: 1712
00:36:29     INFO -  riptData 0000016BC3A43520 with ref count 2 at shutdown
00:36:29     INFO -  ERROR: GC found live SharedScriptData 0000016BC60C2400 with ref count 2 at shutdown
...
00:36:29     INFO -  [Child 8308, Main Thread] ###!!! ASSERTION: Component Manager being held past XPCOM shutdown.: 'cnt == 0', file z:/build/build/src/xpcom/build/XPCOMInit.cpp, line 968
00:36:29     INFO -  Leaked URLs:
00:36:29     INFO -    http://127.0.0.1:50190/layout/mozilla_governance.html
00:36:29     INFO -  nsStringStats
00:36:29     INFO -   => mAllocCount:          10050
00:36:29     INFO -   => mReallocCount:            0
00:36:29     INFO -   => mFreeCount:            8529  --  LEAKED 1521 !!!
00:36:29     INFO -   => mShareCount:           7678
00:36:29     INFO -   => mAdoptCount:            587
00:36:29     INFO -   => mAdoptFreeCount:        591
00:36:29     INFO -   => Process ID: 8308, Thread ID: 2620
00:37:38     INFO - TEST-UNEXPECTED-ERROR | testing\firefox-ui\tests\functional\sessionstore\test_restore_windows_after_windows_shutdown.py TestWindowsShutdownForcedSessionRestore.test_manual_restart | IOError: Process still running 70s after quit request
00:37:38     INFO - Traceback (most recent call last):
00:37:38     INFO -   File "Z:\task_1546472867\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 159, in run
00:37:38     INFO -     testMethod()
00:37:38     INFO -   File "Z:\task_1546472867\build\tests\firefox-ui\tests\testing\firefox-ui\tests\functional\sessionstore\test_restore_windows_after_windows_shutdown.py", line 69, in test_manual_restart
00:37:38     INFO -     self.windows_shutdown_with_variety(restart_by_os=False, expect_restore=False)
00:37:38     INFO -   File "Z:\task_1546472867\build\tests\firefox-ui\tests\testing\firefox-ui\tests\functional\sessionstore\session_store_test_case.py", line 310, in windows_shutdown_with_variety
00:37:38     INFO -     self.marionette.quit(in_app=True, callback=lambda: self.simulate_os_shutdown())
00:37:38     INFO -   File "Z:\task_1546472867\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _
00:37:38     INFO -     return func(*args, **kwargs)
00:37:38     INFO -   File "Z:\task_1546472867\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1128, in quit
00:37:38     INFO -     raise IOError(message.format(self.shutdown_timeout))
00:37:38     INFO - TEST-INFO took 127019ms
00:37:38    ERROR - test_end for testing\firefox-ui\tests\functional\sessionstore\test_restore_windows_after_windows_shutdown.py TestWindowsShutdownForcedSessionRestore.test_manual_restart logged while not in progress. Logged with data: {"status": "ERROR", "extra": {"class_name": "test_restore_windows_after_windows_shutdown.TestWindowsShutdownForcedSessionRestore", "method_name": "test_manual_restart"}, "expected": "PASS", "test": "testing\\firefox-ui\\tests\\functional\\sessionstore\\test_restore_windows_after_windows_shutdown.py TestWindowsShutdownForcedSessionRestore.test_manual_restart", "message": "InvalidSessionIdException: Please start a session", "stack": "Traceback (most recent call last):\n  File \"Z:\\task_1546472867\\build\\venv\\lib\\site-packages\\marionette_harness\\marionette_test\\testcases.py\", line 190, in run\n    self.tearDown()\n  File \"Z:\\task_1546472867\\build\\tests\\firefox-ui\\tests\\testing\\firefox-ui\\tests\\functional\\sessionstore\\session_store_test_case.py\", line 65, in tearDown\n    super(SessionStoreTestCase, self).tearDown()\n  File \"Z:\\task_1546472867\\build\\venv\\lib\\site-packages\\firefox_puppeteer\\mixins.py\", line 97, in tearDown\n    self.marionette.set_context('chrome')\n  File \"Z:\\task_1546472867\\build\\venv\\lib\\site-packages\\marionette_driver\\marionette.py\", line 1461, in set_context\n    {\"value\": context})\n  File \"Z:\\task_1546472867\\build\\venv\\lib\\site-packages\\marionette_driver\\decorators.py\", line 26, in _\n    return func(*args, **kwargs)\n  File \"Z:\\task_1546472867\\build\\venv\\lib\\site-packages\\marionette_driver\\marionette.py\", line 753, in _send_message\n    raise errors.InvalidSessionIdException(\"Please start a session\")\n"}

Comment 1

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

Similar to bug 1517106 which covers a shutdown hang of Firefox, which is most likely triggered by bug 1486101.

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-central: 3

Platform breakdown:
* windows10-64-ccov: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1517377&startday=2018-12-31&endday=2019-01-06&tree=all

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 2

Platform breakdown:

• windows10-64-ccov: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1517377&startday=2019-01-07&endday=2019-01-13&tree=all

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 3

Platform breakdown:

• windows10-64-ccov: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1517377&startday=2019-01-21&endday=2019-01-27&tree=all

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 6

Platform breakdown:

• windows10-64-ccov: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1517377&startday=2019-01-28&endday=2019-02-03&tree=all

Comment 6

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 6

Platform breakdown:

• windows10-64-ccov: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1517377&startday=2019-02-04&endday=2019-02-10&tree=all

Comment 7

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

Most likely fixed by the upgrade of Windows workers to 1803 by bug 1522896.