Cleaning up owned dbus names on shutdown with glib

[Daniel Drake <dsd laptop org>]

Hi,

I'm battling a problem where imsettings, running as part of the
desktop session, causes a delay between 5 and 20 seconds on every
system shutdown, while it is trying to clean up dbus stuff.

When shutting down, systemd quickly sends TERM signals to everything
in the display manager cgroup, including the session bus dbus-daemon
itself, and imsettings. Everything gets killed pretty quick but of
course the exact order of signal reception and processing will vary.


imsettings is a little daemon that deals with input methods. It hosts
a dbus service on the session bus, claiming exactly one bus name with
g_bus_own_name_on_connection().
The source code is: git://github.com/tagoh/imsettings.git

imsettings-daemon/main.c is the main daemon in question, and
imsettings-daemon/imsettings-server.c is the IMSettingsServer class
implementation which is the GObject that claims the bus name and so
on.

I have made some minor changes to try and fix this in this patch:
http://dev.laptop.org/~dsd/20110928/imsettings-shutdown.patch
but none have worked right.


Is imsettings doing something wrong, or have we come across a bug in glib?

Here's whats happening during shutdown:

1. imsettings receives SIGTERM, which it has a handler for
2. The SIGTERM handler asks the glib main loop to quit
3. After the glib main loop ends, imsettings main() destroys its
IMSettingsServer object, which is what was owning the bus name
4. imsettings_server_finalize() calls g_bus_unown_name() which then
hangs for 5-20 seconds, then complains:

[ 1317208397.833711]: GLib-GIO[2630]: WARNING **: Error releasing name
com.redhat.imsettings: Timeout was reached

[ 1317208397.834972]: GLib-GIO[2630]: CRITICAL **: Error while sending
AddMatch() message: The connection is closed

[ 1317208397.835505]: GLib-GIO[2630]: CRITICAL **: Error while sending
AddMatch() message: The connection is closed

Then exit completes.


Note that the IMSettingsServer object never received its name_lost
callback above. If it had done so, the code (with the very last bit of
my patch) knows not to try and unown the name and I guess that would
have avoided the long timeout.

If I add a call to g_dbus_connection_close_sync() before trying to
unown the name, shutdown completes instantaneously. It does complain:

    GLib-GIO[2630]: WARNING **: Error releasing name
com.redhat.imsettings: The connection is closed

but that's what I was expecting.

However, that doesn't seem like the right fix. Ordinarily, outside of
the shutdown path, if imsettings receives SIGTERM it should unown its
bus name and exit cleanly, and it wouldn't be able to do this if the
preceding code had just closed the connection.


So I am wondering if I have found a bug in the dbus message sending
internals of glib. I guess what is happening is that at the time when
imsettings starts processing its SIGTERM signal, the session bus is
still alive and kicking. Then, approximately at the same time as when
it tries to unown the name, the session bus gets killed. This causes
the unown call to hang for a long time.
What should perhaps happen here is that if the session bus goes away
at the same time as the unown call, glib internals should notice this
and make the ongoing unown call return failure immediately, rather
than waiting a long time for the timeout.

Or is imsettings doing something wrong?

Let me know how I can debug this further - I can reproduce it trivially.

Thanks,
Daniel