After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 688209 - Slow shutdown when a client connects at a late stage
Slow shutdown when a client connects at a late stage
Status: RESOLVED FIXED
Product: gnome-session
Classification: Core
Component: gnome-session
3.6.x
Other Linux
: Normal normal
: ---
Assigned To: Session Maintainers
Session Maintainers
Depends on:
Blocks:
 
 
Reported: 2012-11-12 21:30 UTC by Daniel Drake
Modified: 2012-11-13 14:49 UTC
See Also:
GNOME target: ---
GNOME version: 3.5/3.6


Attachments
full gnome-session debug log (92.86 KB, text/plain)
2012-11-12 21:30 UTC, Daniel Drake
  Details
patch (6.51 KB, patch)
2012-11-12 21:32 UTC, Daniel Drake
accepted-commit_now Details | Review

Description Daniel Drake 2012-11-12 21:30:01 UTC
Created attachment 228831 [details]
full gnome-session debug log

Running GNOME 3.6 (fallback mode) on OLPC XO laptops, the logout process is delayed by about one minute.

http://dev.laptop.org/ticket/12210

This seems to be because we are running maliit, an on-screen keyboard activated via a GTK+ input method plugin. When gnome-session asks maliit-server to shut down, maliit gets automatically started again because there are still active GTK+ applications running which are using it.

This has highlighted two issues: firstly, gnome-session starts rejecting new client registrations at this time (see on_xsmp_client_register_request) which causes libSM to go into an infinite loop. http://lists.x.org/archives/xorg-devel/2012-November/034436.html

With that fixed, gnome-session still hangs for a long time on shutdown, because it is still confused about the new SM client appearing very late in the game. The relevant lines in the log are:

GsmXsmpServer: accept_ice_connection()
GsmXsmpServer: auth_ice_connection()
GsmXSMPClient: Setting up new connection
GsmXSMPClient: New client '0xa068150 []'
GsmStore: Adding object id /org/gnome/SessionManager/Client8 to store
GsmManager: Client added: /org/gnome/SessionManager/Client8
GsmXSMPClient: Initializing client 0xa068150 []
GsmXSMPClient: Client '0xa068150 []' received RegisterClient(NULL)
GsmXSMPClient:   rejected: invalid previous_id
GsmDBusClient: obj_path=/org/freedesktop/DBus interface=org.freedesktop.DBus method=NameOwnerChanged
GsmDBusClient: obj_path=/org/freedesktop/DBus interface=org.freedesktop.DBus method=NameOwnerChanged
GsmManager: disconnect client: /org/gnome/SessionManager/Client3
GsmManager: in shutdown, not restarting application
GsmStore: Unreffing object: 0xa046088
GsmClient: disposing /org/gnome/SessionManager/Client3
GsmStore: emitting removed for /org/gnome/SessionManager/Client3
GsmManager: Client removed: /org/gnome/SessionManager/Client3
GsmAutostartApp: (pid:3479) done (status:0)
App gnome-settings-daemon.desktop exited with 0
GsmAutostartApp: (pid:3509) done (status:0)
App gnome-panel.desktop exited with 0
** Message: applet now removed from the notification area
GsmManager: RegisterClient 
Unable to register client: shutting down

Now there is a long pause. Then:

GsmManager: client failed to stop: /org/gnome/SessionManager/Client8, 
GsmManager: ending phase EXIT

Full log attached.

Here is a patch to fix this. It moves XSMP server management into GsmManager. That way, we can inform the XSMP server to stop accepting new connections at a much earlier stage when we are shutting down. Now the late-connecting client is rejected cleanly at an earlier stage and the long shutdown delay is gone.
Comment 1 Daniel Drake 2012-11-12 21:32:43 UTC
Created attachment 228833 [details] [review]
patch
Comment 2 Colin Walters 2012-11-12 22:08:32 UTC
Review of attachment 228833 [details] [review]:

At a high level, the patch makes sense, and clearly it solves a real problem.

The question I am wondering about is - is there a reason that we were creating the XSMP server before grabbing the dbus name?  I can't think offhand of one...but the current code structure is slightly odd.  (Why are we creating a GsmStore outside of GsmManager?)

Anyways, two minor coding style things:

::: gnome-session/gsm-manager.c
@@ +2522,3 @@
+                g_object_unref (manager->priv->xsmp_server);
+                manager->priv->xsmp_server = NULL;
+        }

g_clear_object ()

::: gnome-session/gsm-xsmp-server.c
@@ +253,3 @@
+{
+        g_return_if_fail (GSM_IS_XSMP_SERVER (server));
+        g_debug("gsm_xsmp_server_stop");

Missing space between identifier and paren
Comment 3 Ray Strode [halfline] 2012-11-12 23:23:36 UTC
Review of attachment 228833 [details] [review]:

::: gnome-session/gsm-manager.c
@@ +1589,3 @@
                 break;
         case GSM_MANAGER_PHASE_QUERY_END_SESSION:
+                gsm_xsmp_server_stop (manager->priv->xsmp_server);

I think I wouldn't call this _stop since the xsmp server is still running afterward servicing the last two phases for session clients before exiting.  Maybe "stop_accepting_new_clients" ?
Comment 4 Daniel Drake 2012-11-13 14:49:34 UTC
I agree, I don't think there is a special reason that we created the xsmp server before taking the dbus name.

Pushed with the suggested changes to gnome-3-6 (652f982b6bf3836c8f23c4ff718b4781d8314623) and master (59af0bd778e2a71b56d78f4b17517cbce16d2f74). Thanks for the fast review.