1787716 - Marionette client doesn't mark session as deleted when an "in_app" shutdown is requested

Status: RESOLVED FIXED

(Remote Protocol :: Marionette, defect, P1)

Description

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

In case of shutdown hangs of Firefox and reaching its toolkit.asyncshutdown.crash_timeout value Marionette will bail out but in case of CCOV builds as seen below would not actually force-kill the actual browser process. Hereby my patch from bug 1697047 might be needed.

What I can see in the logs:

1661766526123   Marionette      DEBUG   5 <- [1,14,null,{"cause":"shutdown","forced":false}]
1661766526189   Marionette      DEBUG   Closed connection 5
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3ea321c00 - BlockShutdown: CanSend.: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:3671
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3ea321c00 - ShutDownProcess: Shutdown already pending.: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:1824
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3eaeb3a00 - BlockShutdown: CanSend.: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:3671
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3eaeb3a00 - ShutDownProcess: Sent shutdown message.: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:1803
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3eaeb3000 - BlockShutdown: CanSend.: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:3671
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3eaeb3000 - ShutDownProcess: Sent shutdown message.: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:1803
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3ed440f00 - BlockShutdown: CanSend.: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:3671
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3ed440f00 - ShutDownProcess: Sent shutdown message.: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:1803
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3eaeb3a00 - ShutDownProcess: Closing channel.: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:1843
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3eaeb3a00 - RemoveShutdownBlockers: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:3786
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3eaeb3000 - ShutDownProcess: Closing channel.: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:1843
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3eaeb3000 - RemoveShutdownBlockers: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:3786
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3ed440f00 - ShutDownProcess: Closing channel.: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:1843
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3ed440f00 - RemoveShutdownBlockers: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:3786
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3ea321c00 - ShutDownProcess: Closing channel.: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:1843
[Parent 10340, Main Thread] WARNING: ContentParent: id=2f3ea321c00 - RemoveShutdownBlockers: file Z:/task_166175583971947/build/src/dom/ipc/ContentParent.cpp:3786
Waiting in WillDestroyCurrentMessageLoop for pid 11860
 5:00.81 TEST_END: ERROR, expected PASS - OSError: Process still running 190.0s after quit request
Traceback (most recent call last):
  File "c:\mozilla\mozilla-unified\testing\marionette\harness\marionette_harness\marionette_test\testcases.py", line 202, in run
    testMethod()
  File "C:\mozilla\mozilla-unified\testing\marionette\harness\marionette_harness\tests\unit\test_quit_restart.py", line 330, in test_in_app_quit
    details = self.marionette.quit(in_app=True)
  File "c:\mozilla\mozilla-unified\testing\marionette\client\marionette_driver\decorators.py", line 27, in _
    return func(*args, **kwargs)
  File "c:\mozilla\mozilla-unified\testing\marionette\client\marionette_driver\marionette.py", line 1032, in quit
    raise IOError(message.format(self.shutdown_timeout))
​
 5:00.81 INFO Application command: firefox/firefox.exe -no-remote -marionette --wait-for-browser -profile C:\Users\henrik\AppData\Local\Temp\tmp8xehj4h2.mozrunner
1661766722887   Marionette      INFO    Marionette enabled

Given that the session is already closed Marionette should end-up in cleanup() and then should stop the runner via the mozprocess handler.

Given that nothing additionally gets logged by this code from the process class we most likely would hit the else case and do nothing?

Comment 1

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

The problem here is actually that the Marionette client doesn't mark the current session as deleted in case of a requested in_app quit:

https://searchfox.org/mozilla-central/rev/380fc5571b039fd453b45bbb64ed13146fe9b066/testing/marionette/client/marionette_driver/marionette.py#1013-1018

That means within the cleanup() method we end-up trying to delete the session again by sending WebDriver:DeleteSession. This will fail because there is no active connection and no session anymore.

If then the application would even hang during shutdown our code would never fallback to force kill the current instance and as such might even leave a running instance behind.

I would propose this fix which is needed to make progress on the CCOV shutdown hangs as M4:external.

Comment 2

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

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

The problem here is actually that the Marionette client doesn't mark the current session as deleted in case of a requested in_app quit:

https://searchfox.org/mozilla-central/rev/380fc5571b039fd453b45bbb64ed13146fe9b066/testing/marionette/client/marionette_driver/marionette.py#1013-1018

I actually missed that the session deletion happens in line 1035 but it should indeed happen immediately when the application is going to shutdown.

That means within the cleanup() method we end-up trying to delete the session again by sending WebDriver:DeleteSession. This will fail because there is no active connection and no session anymore.

If then the application would even hang during shutdown our code would never fallback to force kill the current instance and as such might even leave a running instance behind.

Well, and here we do not have a else case but we always fallback to force cleaning the instance.

As such I will go ahead and refactor the client code a little bit. Further lets improve our Marionette unit tests to ensure that the application process is checked if it is gone or still present - depending on the type of test.

Comment 3

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

Attachment: Bug 1787716 - [marionette] Improvements for quitting the application from within itself.

Comment 4

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/a68b4b953d99
[marionette] Improvements for quitting the application from within itself. r=webdriver-reviewers,jdescottes,jgraham

Comment 5

[Marian-Vasile Laza]

https://hg.mozilla.org/mozilla-central/rev/a68b4b953d99