GNOME Bugzilla – Bug 726060
Password prompt initiated before D-Bus name acquired
Last modified: 2014-03-26 07:24:34 UTC
Overview: Evolution hangs on startup when I add four Exchange EWS accounts. Loads forever. Steps to reproduce: I configured Evolution to use four seperate accounts on an Exchange 2013 SP1 server via EWS. Accounts connected, mails and folders were available. I waited until all folders had been loaded, then closed Evolution and opened Evolution again. Actual results: Now when opening Evolution I see all four accounts, but instead of loading the folder tree it shows "Loading..." for all accounts. Waited for hours, nothing happens. Expected results: The program should load the accounts and folders as before. Builds: - Evolution 3.10.4 on Manjaro - Evolution 3.8.4 on Xubuntu
Thanks for a bug report. Could you install debuginfo packages for evolution-data-server, evolution and evolution-ews and then capture a backtrace of running evolution processes, which should show where it got stock, please? Alternatively, you can also run evolution from a console like this: $ EWS_DEBUG=2 evolution which will print raw communication between the server and the client on a console, though it might be hard to follow due to an interleave of four accounts. The gdb commands to get the backtraces is: $ gdb --batch --ex "t a a bt" -pid=`pidof evolution` &>evo.txt $ gdb --batch --ex "t a a bt" -pid=`pidof evolution-source-registry` &>esr.txt
I can't find any debuginfo packages when searching in the Manjaro package manager. Sorry, absolute newbie in this case. How do I install these? When running with the debug setting I see the following: [meinereiner@tranquilitatis ~]$ EWS_DEBUG=2 evolution ** (evolution:1482): 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. (evolution:1482): Gtk-WARNING **: Failed to register client: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.gnome.SessionManager was not provided by any .service files ** (evolution-alarm-notify:1488): 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. java version "1.7.0_51" OpenJDK Runtime Environment (IcedTea 2.4.5) (ArchLinux build 7.u51_2.4.5-1-x86_64) OpenJDK 64-Bit Server VM (build 24.51-b03, mixed mode) [meinereiner@tranquilitatis ~]$ I can close Evolution normally in this case, but it is not showing the mailbox folder tree.
(In reply to comment #2) > I can't find any debuginfo packages when searching in the Manjaro package > manager. Sorry, absolute newbie in this case. How do I install these? I do not know how your distribution provides debuginfo packages, some use -dbg suffix. If you do not have these, then just try to gather the backtraces and we'll see whether you have debuginfo of some sort already installed. > When running with the debug setting I see the following: > > [meinereiner@tranquilitatis ~]$ EWS_DEBUG=2 evolution Those warnings are normal when not using gnome-shell, and/or when not having enabled/installed accessibility - they are unrelated to the issue. There should be many other debugging information, if the evolution tries to access the server at all, which doesn't seem to be the case here. I suppose you didn't have any other evolution running when invoking the command.
Created attachment 272405 [details] ESR backtrack
Created attachment 272406 [details] EVO backtrack
Okay, I installed the packages on Ubuntu. Looks like there are no Evolution debug packages available for Manjaro. I ran the gdb commands and added the resulting logfiles. Hope this is something that can help.
Created attachment 272407 [details] ESR backtrack Manjaro
Created attachment 272408 [details] EVO backtrack Manjaro
Thanks for the update. I see the evolution-source-registry is in a process of authenticating towards an EWS account, but it doesn't move further. It seems the password is either missing or incorrect. Could you run that process from a terminal with enabled EWS debugging, please? You can do it like this: $ EWS_DEBUG=2 /usr/libexec/evolution-source-registry It's enough to do this, because the process itself tries to do the authentication when searching for available folders. By the way, what is the exact version of evolution-data-server and evolution-ews, please? You may install debug info packages for these two packages as well.
I have ran the command... this is the result: Migrating mail accounts from GConf... Migrating addressbook sources from GConf... Migrating calendar sources from GConf... Migrating task list sources from GConf... Migrating memo list sources from GConf... Registering EYahooBackendFactory ('yahoo') Registering EOwncloudBackendFactory ('owncloud') Registering EMapiBackendFactory ('mapi') Registering EEwsBackendFactory ('ews') Registering EGoogleBackendFactory ('google') Registering ECollectionBackendFactory ('none') account01@example.com: Pairing 1393967236.1958.19@r400 with resource global-address-list Adding 1393967236.1958.19@r400 ('Source') Adding 1393967196.7011.2@r400 ('Source_1') Adding vfolder ('Source_2') account02@example.com: Pairing 1393958102.1958.0@r400 with resource global-address-list Adding 1393958102.1958.0@r400 ('Source_3') Adding 1393958053.3892.2@r400 ('Source_4') Adding 1393958053.3892.17@r400 ('Source_5') Adding 1393958053.3892.5@r400 ('Source_6') account03@example.com: Pairing 1393958513.1958.10@r400 with resource global-address-list Adding 1393958513.1958.10@r400 ('Source_7') Adding 1393958460.5398.4@r400 ('Source_8') Adding 1393958460.5398.19@r400 ('Source_9') Adding 1393958460.5398.2@r400 ('Source_10') Adding 1393967196.7011.5@r400 ('Source_11') Adding 1393967196.7011.0@r400 ('Source_12') Adding local ('Source_13') Adding 1393958053.3892.0@r400 ('Source_14') account04@example.com: Pairing 1393852290.3095.0@r400 with resource global-address-list Adding 1393852290.3095.0@r400 ('Source_15') Adding 1393852241.3089.2@r400 ('Source_16') Adding 1393852241.3089.17@r400 ('Source_17') Adding 1393852241.3089.0@r400 ('Source_18') Adding 1393852241.3089.5@r400 ('Source_19') Adding 1393967196.7011.17@r400 ('Source_20') Adding 1393958460.5398.7@r400 ('Source_21') Adding caldav-stub ('Source_22') Adding contacts-stub ('Source_23') Adding google-stub ('Source_24') Adding ldap-stub ('Source_25') Adding local-stub ('Source_26') Adding weather-stub ('Source_27') Adding webcal-stub ('Source_28') Adding webdav-stub ('Source_29') Adding birthdays ('Source_30') Adding sendmail ('Source_31') Adding system-address-book ('Source_32') Adding system-calendar ('Source_33') Adding system-memo-list ('Source_34') Adding system-task-list ('Source_35') module-cache-reaper-Message: Scanning data directories module-cache-reaper-Message: Scanning cache directories Server is up and running... AUTH (1393967196.7011.2@r400): Initiated AUTH (1393958053.3892.2@r400): Initiated AUTH (1393958460.5398.4@r400): Initiated AUTH (1393852241.3089.2@r400): Initiated Bus name 'org.gnome.evolution.dataserver.Sources1' acquired. The process is still running, but there are no further messages from this point. evolution-data-server 3.8.5-1ubuntu3 evolution-ews 3.8.4-0ubuntu1 Debug packages for the data-server are already installed, for ews there is no Ubuntu debug package available or I can't find it.
And I tried this on Manjaro also. The log stopped at the same point. There I have the following versions installed: evolution-data-server 3.10.4-1 evolution-ews 3.10.4-1
Thanks for the update. I see it does something, concretely it started authentication procedure for four sources: > AUTH (1393967196.7011.2@r400): Initiated > AUTH (1393958053.3892.2@r400): Initiated > AUTH (1393958460.5398.4@r400): Initiated > AUTH (1393852241.3089.2@r400): Initiated it should continue shortly after it. From that I'd say that evolution has some trouble connecting to libsecret and/or gnome-keyring. Is the gnome-keyring-daemon running on your machine? Could you run the source registry with GCR_DEBUG=all instead? It's like: $ GCR_DEBUG=all /usr/libexec/evolution-source-registry It'll print another set of warnings. Maybe this is related to bug #680961.
The gnome-keyring-daemon has been started. I had a look into the saved data of the keyring and I removed the saved passwords of the Evolution mailaccounts. Now I ran the source registry with GCR_DEBUG=all and go this: AUTH (1393967196.7011.2@r400): Initiated AUTH (1393958053.3892.2@r400): Initiated AUTH (1393852241.3089.2@r400): Initiated AUTH (1393958460.5398.4@r400): Initiated Bus name 'org.gnome.evolution.dataserver.Sources1' acquired. (process:4275): Gcr-DEBUG: gcr_system_prompt_open_for_prompter: opening prompt (process:4275): Gcr-DEBUG: perform_init_async: connecting to bus (process:4275): Gcr-DEBUG: gcr_system_prompt_open_for_prompter: opening prompt (process:4275): Gcr-DEBUG: perform_init_async: connecting to bus (process:4275): Gcr-DEBUG: gcr_system_prompt_open_for_prompter: opening prompt (process:4275): Gcr-DEBUG: perform_init_async: connecting to bus (process:4275): Gcr-DEBUG: on_bus_connected: connected to bus (process:4275): Gcr-DEBUG: perform_init_async: calling BeginPrompting method on prompter (process:4275): Gcr-DEBUG: gcr_system_prompt_open_for_prompter: opening prompt (process:4275): Gcr-DEBUG: perform_init_async: connecting to bus (process:4275): Gcr-DEBUG: on_bus_connected: connected to bus (process:4275): Gcr-DEBUG: perform_init_async: calling BeginPrompting method on prompter (process:4275): Gcr-DEBUG: on_prompter_begin_prompting: registered prompt org.gnome.keyring.SystemPrompter: /org/gnome/keyring/Prompt/p0 (process:4275): Gcr-DEBUG: gcr_system_prompt_get_secret_exchange: creating new secret exchange (process:4275): Gcr-DEBUG: gcr_secret_exchange_set_property: automatically selecting secret exchange protocol (process:4275): Gcr-DEBUG: gcr_secret_exchange_receive: receiving secret exchange: [sx-aes-1]\npublic=xxxxxxxxxxx\n (process:4275): Gcr-DEBUG: gcr_secret_exchange_default_generate_exchange_key: generating public key (process:4275): Gcr-DEBUG: on_prompter_begin_prompting: registered prompt org.gnome.keyring.SystemPrompter: /org/gnome/keyring/Prompt/p1 (process:4275): Gcr-DEBUG: derive_key: deriving shared transport key (process:4275): Gcr-DEBUG: gcr_secret_exchange_default_derive_transport_key: deriving transport key (process:4275): Gcr-DEBUG: perform_prompt_async: prompting for password (process:4275): Gcr-DEBUG: gcr_secret_exchange_send: sending the secret exchange: [sx-aes-1]\npublic=xxxxxxxxxxxx\n (process:4275): Gcr-DEBUG: gcr_secret_exchange_receive: receiving secret exchange: [sx-aes-1]\npublic=xxxxxxxxxxxx\n (process:4275): Gcr-DEBUG: gcr_secret_exchange_default_decrypt_transport_data: decrypting data I have exchanged the secrets through "xxxxx"... I see a password prompt for one of the mail accounts. When I enter the password, the last line of the log appears but nothing else. The password prompt will not close until I cancel the window. There are no password prompts for the other accounts nor do I see any more messages.
Thanks for the update. It took me some time to figure out why GCR_DEBUG didn't work for me, then I realized that the debug output from gcr is there only if the passwords are not saved in keyring already. I have configured 3 EWS accounts. I see my output is different, specifically, yours "AUTH (xxxx): Initiated" is invoked before the Bus name is acquired, while mine are initiated only after it is acquired. I guess this is the reason for the issue, the authentication requests are piled in a queue before the process is fully initialized. I'll try to look what I can do regarding this. By any chance, are you able to test any possible patches which might be attached here for testing, please?
That shouldn't be possible. None of the EDS services even export a D-Bus interface until they've successfully acquired their well-known bus name. Might just be where the methods chain up that make the log look like that. See: https://git.gnome.org/browse/evolution-data-server/tree/libebackend/e-source-registry-server.c#n1100 https://git.gnome.org/browse/evolution-data-server/tree/addressbook/libedata-book/e-data-book-factory.c#n568 https://git.gnome.org/browse/evolution-data-server/tree/calendar/libedata-cal/e-data-cal-factory.c#n568
(In reply to comment #13) > I see a password prompt for one of the mail accounts. When I enter the > password, the last line of the log appears but nothing else. The password > prompt will not close until I cancel the window. There are no password prompts > for the other accounts nor do I see any more messages. I can reproduce this when I hack/tweak the code to initiate the password prompt before the D-Bus name is acquired. It's a gross hack, but shows what you see. The hack looks like this: diff --git a/libebackend/e-dbus-server.c b/libebackend/e-dbus-server.c index e2f58db..d1e2bd2 100644 --- a/libebackend/e-dbus-server.c +++ b/libebackend/e-dbus-server.c @@ -204,6 +204,13 @@ dbus_server_bus_name_lost (EDBusServer *server, e_dbus_server_quit (server, E_DBUS_SERVER_EXIT_NORMAL); } +static gboolean +quit_loop_cb (gpointer user_data) +{ + g_main_loop_quit (user_data); + return FALSE; +} + static EDBusServerExitCode dbus_server_run_server (EDBusServer *server) { @@ -216,6 +223,9 @@ dbus_server_run_server (EDBusServer *server) class->bus_name != NULL, E_DBUS_SERVER_EXIT_NONE); + g_timeout_add_seconds (2, quit_loop_cb, server->priv->main_loop); + g_main_loop_run (server->priv->main_loop); + server->priv->bus_owner_id = g_bus_own_name ( G_BUS_TYPE_SESSION, class->bus_name, [mcrha@zyxPad evolution-data-server]$
(In reply to comment #15) > That shouldn't be possible. None of the EDS services even export a D-Bus > interface until they've successfully acquired their well-known bus name. Well, no, the problem is that the 'collection' module in the source-registry itself initiated the password prompt/request before the source registry is fully up. Below is a backtrace caught when source_registry_server_maybe_start_auth_session is called inside the source registry process:
+ Trace 233393
Thread 1 (Thread 0x7ffff746ea00 (LWP 24063))
Ah, you're right. I'd say the right way to do this is to load sources after the service acquires its bus name, but before exporting its own D-Bus interface. Currently sources are loaded from main() before the main loop even starts: https://git.gnome.org/browse/evolution-data-server/tree/services/evolution-source-registry/evolution-source-registry.c#n182 Maybe move that "load_all" call to a EDBusServer:bus-acquired signal handler?
Created attachment 272868 [details] [review] proposed eds patch for evolution-data-server; (In reply to comment #18) > Maybe move that "load_all" call to a EDBusServer:bus-acquired signal handler? Yes, it seems to do the trick. At least for my ugly hack. meinereiner, are you able to give this a try, please? It'll be safer to see that it works for you too, especially in your environment, where you get the real issue.
Sorry, I have no idea what to do with these diffs. I'm just a user at beginners level. Either I need a step by step explanation or others have to test this.
(In reply to comment #20) > Sorry, I have no idea what to do with these diffs. I'm just a user at beginners > level. Either I need a step by step explanation or others have to test this. OK, that's no problem. I do not know how to build test packages for Ubuntu-like distributions, I would be able to help with Fedora only. Maybe if you ask the package maintainer of the evolution-data-server package of your distribution (preferably the one with 3.10.4), then he/she will be able to provide you the build with the patch included. Nonetheless, I'm committing this to sources, thus it'll be available in the future updates. We can reopen the bug report, if you'll face of the issue even with the patch included. Thanks for your help with the investigation. Created commit c1a53c0 in eds master (3.13.1+) [1] Created commit b4665e2 in eds evolution-data-server-3-12 (3.12.1+) [1] https://git.gnome.org/browse/evolution-data-server/commit/?id=c1a53c0