Bug 973613

I'm guessing this should probably be a blocker, given that beta criteria must be met (and logout is one of them). Marking as such - let's see what happens.

I also tried running gnome-session-quit --logout with and without --no-prompt option. Same deal.

I've seen this on my T510 (Intel graphics) and a remote VM (llvmpipe) running through xrdp.

Please try with shell 3.8.3-2. Thanks.

(In reply to Adam Williamson from comment #3)
> Please try with shell 3.8.3-2. Thanks.

Hmm, this seems empty:

http://dl.fedoraproject.org/pub/fedora/linux/updates/19/x86_64/

I'll wait a bit for it to come good gain...

Or maybe it's supposed to go into the development packages hierarchy... Cannot remember right now. Anyhow, yum says it's not there yet. Will get back to you when I get it and test it...

it will wind up in development/19, yeah. it's being pushed from updates-testing to there ATM. updates/ is not used until post-release (well, post go/no-go). You can grab packages from Koji if you want to avoid the wait, though.

(In reply to Adam Williamson from comment #3)
> Please try with shell 3.8.3-2. Thanks.

Same. As long as I have a couple of windows open (I usually open terminal and evo), it won't log me out. Empty desktop, yes.

I use Kerberos authentication and my account is in openldap, if it matters. The whole thing goes through sssd. No change on that front since F-18 (in fact, the server is still F-18).

It may well matter (I haven't had any problem with logging out with local auth throughout GNOME 3.8, though I'm not sure I've specifically tried with the latest stuff yet).

Can you attach 'journalctl -a' output after a failed logout attempt?

All the "logout" item does is call out to gnome-session and request a logout - as the behavior is the same when calling gnome-session-quit, the problem is likely on the gnome-session side.

Created attachment 761010 [details]
journalctl -a after unsuccessful logout

In this particular case, Firefox got killed and desktop stayed up.

Another interesting piece of information is that logout actually does happen - a minute or so after it has been requested. Changing the title of the bug. Removing blocker, because it is just slow.

On my remote VM it took about 2 minutes to logout.

PS. When it was not happening before, I'd just kill things by hand. Not a very patient man, I guess...

On both the local system and the remote VM journal has various events, then a pause of about a minute and a half, then this:
---------------
Jun 18 08:08:15 shrek.rexursive.com gdm-password][5903]: pam_unix(gdm-password:s
ession): session closed for user bojan
---------------

Or this:
---------------
Jun 18 09:29:40 <remote-host> xrdp-sesman[837]: pam_unix(xrdp-ses
man:session): session closed for user <user>
---------------

Not sure whether this is a red herring or what. Both systems use sssd for authentication (krb5 and ldap underneath, local against OpenLDAP, remote against AD).

Seems to be caused by Evolution.

This is what I tried:

- created a local account, logged in, started terminal and FF - no problem
- same local account, start Evo as well - hang
- same local account, start/stop Evo - no problem
- logged in using a krb5/ldap account that never logged into this system before, started terminal and FF - no problem
- same new krb5/ldap account, start Evo as well - hang
- same new krb5/ldap account, start/stop Evo - no problem

So, it seems that Evo somehow hangs the logout for about a minute and a half.

BTW, it does not really matter how Evo is used for that hang to happen. IMAP+, EWS or no mail account - same result.

Could you install debuginfo packages for evolution-data-server, evolution, evolution-ews and provide a backtrace of stuck evolution, please? Also, make sure the backtrace will not provide any sensitive information, like passwords, emails addresses, server addresses and so on. I usually search at least for "pass" (quotes for clarity only).

Just noticed that webkitgtk3-debuginfo is 1 GB in size:

http://koji.fedoraproject.org/koji/rpminfo?rpmID=4069139

WTF?

Created attachment 763158 [details]
Backtrace of Evo when logout hangs

Before attempting to log out, I ran gdb -p <evo_pid>. Then, after logout steps, I pressed ^C in gdb and ran t a a bt. The output was set to go to this file.

One more thing - this particular backtrace is from my ThinkPad, which is connected to dovecot using IMAP+. But, as I said before, that bit does not matter. Same hangs happens with my remove VM where I use EWS, as well as with locally configured accounts that used nothing to fetch mail (i.e. just sendmail for sending mail was configured).

Yeah, no need to add webkit debug info, it's a beast.

From the backtrace, the imapx provider tries to save changes to your folder, waiting for a response from the server. That makes me feel like it's waiting for it. The backtrace doesn't show any other activity. On the other hand, I recall an issue with calendar parts, I think it was/is with Memo, where a Memo open blocked evolution's quit. The quit in evolution is postponed until there are any activities in the status bar (basically said), and each view holds its own set of activities. Thus if you move between views, then you see different content in the status bar. When you click each of the views, and check that each of them has no activity shown, then the quit should be quicker. It's only to verify where the issue is.

(In reply to Milan Crha from comment #21)

> From the backtrace, the imapx provider tries to save changes to your folder,
> waiting for a response from the server. That makes me feel like it's waiting
> for it. The backtrace doesn't show any other activity.

The hang happens even when IMAP+ is not configured.

> On the other hand, I
> recall an issue with calendar parts, I think it was/is with Memo, where a
> Memo open blocked evolution's quit. The quit in evolution is postponed until
> there are any activities in the status bar (basically said), and each view
> holds its own set of activities. Thus if you move between views, then you
> see different content in the status bar. When you click each of the views,
> and check that each of them has no activity shown, then the quit should be
> quicker. It's only to verify where the issue is.

Tried that just now. Did not prevent the hang.

Any other ideas I can try?

(In reply to Bojan Smojver from comment #22)
> The hang happens even when IMAP+ is not configured.

Right. That's what reminded me of the Memo open/close bug. I do not recall exact details, I only know that something similar happened to me too, but very sporadically, and whenever I tried to debug it it worked as expected (the quit was immediate).

> Tried that just now. Did not prevent the hang.

I'm not sure what you tried. Could you try to close evolution in each view, and see what the status bar shows during that time, please? I would do it like this:
a) run evolution in the Mailer view;  ($ evolution -c mail)
b) switch to other view
   - if the other view shows pending operation, then wait for it to finish,
   thus the status bar will  be empty
c) close evolution and watch the status bar

Repeat from a), only switch to other view in b). The less mail accounts you'll have configured the better.

(In reply to Milan Crha from comment #23)
> Could you try to close evolution in each view,
> and see what the status bar shows during that time, please? I would do it
> like this:
> a) run evolution in the Mailer view;  ($ evolution -c mail)
> b) switch to other view
>    - if the other view shows pending operation, then wait for it to finish,
>    thus the status bar will  be empty
> c) close evolution and watch the status bar
> 
> Repeat from a), only switch to other view in b). The less mail accounts
> you'll have configured the better.

There is nothing in the status bar and there is no delay (maybe half a second for Tasks and Calendar - but not over a minute like on logout) when I close Evo by hand. Everything happens pretty much instantaneously.

(In reply to Milan Crha from comment #21)
> From the backtrace, the imapx provider tries to save changes to your folder,
> waiting for a response from the server. That makes me feel like it's waiting
> for it.

How does Evo get notified by gnome-session-quit to actually quit? Is it possible that somehow whatever Evo is supposed to listen to is not getting the message?

Oh, I'm sorry, I didn't get that you talk about session Logout, until comment #24. I'm sorry for that, it's my fault.

Evolution is a GtkApplication descendant, thus I suppose it gets the notification through its interface. I'll test this and report back to you when I have something.

Hmm, the logout is instant for me, evolution closes flawlessly here. Could you get a backtrace of "waiting" evolution, just in case it'll show anything useful, please? Just login to a text terminal (like Ctrl+Alt+F2), prepare the command:
   $ gdb --batch --ex "t a a bt" -pid=`pidof evolution` &>bt.txt
and then switch back to X (Alt+F1, or Alt+F7, if you didn't change the setting), call the desktop to Quit and then switch back to the text terminal and invoke the command. Before attaching the backtrace here, please make sure you'll not expose any private information (and you have installed debug info packages for at least evolution-data-server and evolution, of the same version as your binary packages). I usually search at least for "pass" (quotes for clarity only).

The backtrace I attached before was obtained pretty much that way. I just used the logging option of gdb to write to file. And I was in a terminal within X - there is plenty of time to ^C and t a a bt.

Must be something specific to my machines then. Even a brand new account does this (i.e. all defaults).

(In reply to Bojan Smojver from comment #28)
 
> Must be something specific to my machines then. Even a brand new account
> does this (i.e. all defaults).

Any ideas as to what could be causing such a thing even for brand new local accounts?

In fact, if I go through logout steps and then close Evolution, the session exists immediately.

AFAICT, session inhibitors are working fine in Evo, so it's probably not that.

(In reply to Bojan Smojver from comment #29)
> Any ideas as to what could be causing such a thing even for brand new local
> accounts?

I've not much idea, apart of comment #23, I'm sorry.

(In reply to Bojan Smojver from comment #30)
> In fact, if I go through logout steps and then close Evolution, the session
> exists immediately.

What do you mean with 'logout steps'? Does the session manager tell you what application it is waiting for? It does for me, when I want to logout and there is an application waiting for a user input, like when I have opened a new message composer in evolution, which is changed, then it asks whether to discard changes, continue editing or save to drafts.

(In reply to Milan Crha from comment #31)

> What do you mean with 'logout steps'?

Click Log Out on the menu (of the shell), confirm it on the dialog box. So, at that point, the logout should happen, but the desktop is still there, waiting for about a minute and a half (i.e. logout is hung). If I close Evo (by pressing X on its window), the session ends immediately.

> Does the session manager tell you what
> application it is waiting for?

There are no prompts whatsoever on the screen.

> It does for me, when I want to logout and
> there is an application waiting for a user input, like when I have opened a
> new message composer in evolution, which is changed, then it asks whether to
> discard changes, continue editing or save to drafts.

I think that your situation may be different. I have no unfinished tasks in Evo.

Or are you referring to this?

https://git.gnome.org/browse/gnome-session/commit/?id=7b15205dc7e0be6a7d4e8936be7470f09e7777e9

Question: given that both systems that are experiencing the problems are upgrades from F-18, is there a Gnome component that Evo may be expecting to be running, but is not? Some new daemon that fedora-upgrade may not have brought in?

I am having a feeling that Evo may be waiting for something, which then causes gnome-session to wait as well. Of that something isn't there, Evo may wait until timeout is reached. Plausible?

PS. Could you post your loginctl session-status?

Ah, I can reproduce this using gnome-shell. Using for example MATE doesn't exhibit the issue. This is with gnome-shell 3.8.1-4. I'll update the machine to get more recent version.

(In reply to Bojan Smojver from comment #32)
> Or are you referring to this?
> 
> https://git.gnome.org/browse/gnome-session/commit/
> ?id=7b15205dc7e0be6a7d4e8936be7470f09e7777e9

Not intentionally, but the commit seems to be related to "force quit", about which I talked. Currently I see it is not related, as I thought initially.

(In reply to Bojan Smojver from comment #33)
>...

As I can reproduce this now, I will test deeply and let you know when I get anything. I'm currently updating the machine, to work with more recent versions.

   $ G_MESSAGE_DEBUG=all evolution

shows at the end:

> (evolution:6293): Gtk-DEBUG: Received QueryEndSession
> (evolution:6293): Gtk-DEBUG: Calling EndSessionResponse 1 '(null)'
> (evolution:6293): Gtk-DEBUG: Received EndSession
> (evolution:6293): Gtk-DEBUG: Calling EndSessionResponse 1 '(null)'
> (evolution:6293): Gtk-DEBUG: Unregistering client

it's after confirming logout, after that evo is still running. I do not see any point in evolution which might cause this, but there probably is. I even see g_application_quit() being called (gdb stops on it), but nothing more from it.

The link to commit in gnome-session you gave in comment #32 seems related, or at least points to changes in gnome-session which might cause this misbehaviour in evolution.

After a bit more investigation: not using gtk_main*() functions, but g_application_run/_quit(), makes it close on Logout, but it opens two windows on start without arguments, which is not what it should do. It also requires fixing applications flags.

(In reply to Milan Crha from comment #36)
> After a bit more investigation: not using gtk_main*() functions, but
> g_application_run/_quit(), makes it close on Logout, but it opens two
> windows on start without arguments, which is not what it should do. It also
> requires fixing applications flags.

Thanks for sticking with it - much appreciated!

This package has changed ownership in the Fedora Package Database.  Reassigning to the new owner of this component.

I can confirm this bug on Funtoo and Debian Jessie with Gnome 3.14. Any news on this?

Created attachment 955853 [details]
minimal test reproducer

Nope, unfortunately no further updates on this. I spent some time on this today, investigating with a rawhide packages (gtk3-3.15.1-1) and the result is a minimal reproducer, which mimics what Evolution wants to do. The Evolution usage is following:

a) run until a quit is initiated, either by quit of the Evolution, close
   of the last window or the logout/shutdown request by a user
b) on such "quit" prevent session manager from an immediate close and do
   stuff like writing changes into the mail folder or such - just
   a usual quit preparation
c) when this quit preparation is done, let the session manager know that
   the application can be closed and close it too

The communication between the session manager and the Evolution is done by an inhibitor, gtk_application_inhibit() and its counterpart.

The attached test application mimics this behaviour by using 10 seconds timeout before allowing a real quit/logout. It also prints some information when certain functions were called. There are two modes how to run it, one is with '-app' argument, which uses g_application_run() instead of gtk_main (), and another, when there is passed no argument, which uses gtk_main(). Both versions do not work in certain way.

Note the lines with <<< >>> in the below text are only my comments what was happening there, these are not produced by the test application. Also note that the test application doesn't print any runtime warning on its own, those shown are printed by respective library.

------------------------------------------------------------------------------

a) run like evolution
   $ ./test

   ** (test:21068): WARNING **: Couldn't register with accessibility bus:
   Did not receive a reply. Possible causes include: the remote application
   did not send a reply, the message bus security policy blocked the reply,
   the reply timeout expired, or the network connection was broken.
   Hello, before gtk_main() like evo
   Gtk-Message: GtkDialog mapped without a transient parent. This is
   discouraged.
   test_app_window_added: 

      <<< logout was initiated, but nothing happens so far >>>
      <<< thus closing the window on my own (user closes)  >>>

   test_app_window_delete_event_cb: windows:1
   app_shutdown_cb: requested...

   (test:21068): Gtk-WARNING **: Calling Inhibit failed:
   GDBus.Error:org.gnome.SessionManager.GeneralError: Forced logout cannot
   be inhibited
      app_shutdown_cb: new cookie:0

      <<< waited for 10 seconds before real quit >>>

   app_quit_after_shutdown: cookie:0 main-level:1
   Bye, after gtk_main() like evo

To describe the above output, the test application runs and shows a dialog. Then I chose the left-top-icon-area-><login name>->Logout option. I was asked whether I want to logout, which I confirmed. Then I was returned back to the desktop, which didn't do anything, left me looking into the test application's dialog. I closed the dialog, which initiated the shutdown of the GApplication (well, I did it in the code, inside test_app_window_delete_event_cb()). The app_shutdown_cb() callback tried to get the inhibition cookie, which failed, and added a 10 seconds timeout for a real quit confirmation. The session is still waiting for the test application quit, just as expected. After these 10 seconds the test application quits and with it the user is logged out.

------------------------------------------------------------------------------

b) run using g_application_run()
$ ./test -app

   ** (test:20190): WARNING **: Couldn't register with accessibility bus:
   Did not receive a reply. Possible causes include: the remote application
   did not send a reply, the message bus security policy blocked the reply,
   the reply timeout expired, or the network connection was broken.
   Hello, before GtkApplication run
   Gtk-Message: GtkDialog mapped without a transient parent. This is
   discouraged.
   test_app_window_added: 
   app_shutdown_cb: requested...

   (test:20190): Gtk-WARNING **: Calling Inhibit failed:
   GDBus.Error:org.gnome.SessionManager.GeneralError: Forced logout cannot
   be inhibited
      app_shutdown_cb: new cookie:0

      <<< no wait, shuts down immediately >>>

   Bye, after GtkApplication run

Human readable description of the above output is that the test application run properly, then I initiated a Logout request, which resulted into an automatic app_shutdown_cb() call (this one is missing in the case a)). The application fails to get the inhibition cookie again and installs the timeout for a quit, but then it is closed immediately, the timeout callback is never called.

------------------------------------------------------------------------------

From the above, in the a) (run as evolution) the pre-quit phase works nicely, but the automatic shutdown request is not received on a Logout invoke.
In the b) the automatic shutdown request is received properly on a Logout invoke, but the pre-quit phase is not run/finished as expected, which may break user's data.

1) The documentation for GApplication::shutdown is a little unclear - the signal is emitted just before g_application_run returns, it has no relation to gtk_main() or other ways to run a mainloop.

2) What you are trying to do with the inhibitor does not work, currently. The gnome-session protocol has a concept of just-in-time inhibitors for just this case, but it requires to send a EndSessionResponse with is_ok = 0, which we never do in the current GtkApplication code.

See https://people.gnome.org/~mccann/gnome-session/docs/gnome-session.html#id347729

Making just-in-time inhibitors available via GtkApplication would require us to add new API.

(In reply to Matthias Clasen from comment #41)
> 2) What you are trying to do with the inhibitor does not work, currently.
> The gnome-session protocol has a concept of just-in-time inhibitors for just
> this case, but it requires to send a EndSessionResponse with is_ok = 0,
> which we never do in the current GtkApplication code.

It's not exactly what I want, I do not want to prevent the logout, I only want to postpone it. The inhibitors were used only as one of the possible ways (it looked possible at least).

> Making just-in-time inhibitors available via GtkApplication would require us
> to add new API.

I'm fine with "non-working" inhibitors, what I miss is a signal from the SessionManager (received on my end through GApplication), which would tell me that the application should do the close. Once such signal will exist (I hoped in the existing "shutdown" signal), then I could do whatever I want to in that callback. I definitely do not want to add a D-Bus service listener into Evolution, also because the G[tk]Application is capable of these SessionManager signals already, they are only not "properly" (I'm sorry) propagated to the "shutdown" signal (or any new) when the application is not run with g_application_run(). I believe the GApplication received the signal, but because it wasn't in the g_application_run() function then the reaction to that D-Bus signal was void.

This appears to be fixed in F24, so I'm going to rebase and close.