GNOME Bugzilla – Bug 756006
Interaction with git-credential-gnome-keyring broken
Last modified: 2015-10-23 12:06:42 UTC
Since GNOME 3.18, git hangs when attempting to push to github; it's waiting for "git-credential-gnome-keyring store" to finish, and killing this process lets the push continue. It seems that retrieving the cached credentials works fine, but storing the credentials after a successful authentication is broken now. DBus monitoring shows no activity after a completed org.gnome.keyring.internal.Prompter.Callback.PromptReady call from gnome-shell to gnome-keyring. git 2.6.0 libgnome-keyring 3.12.0 gnome-keyring 3.18.0 gnome-shell 3.18.0 systemd v226 (kdbus)
Backtrace of hang:
+ Trace 235545
Debug log up until hang: (process:22576): Gkr-DEBUG: item_create_start: unlocking the keyring: /org/freedesktop/secrets/aliases/default (process:22576): Gkr-DEBUG: gkr_operation_new: 0x1d191e0 (process:22576): Gkr-DEBUG: gkr_operation_block_and_unref: 0x1d191e0: processing (process:22576): Gkr-DEBUG: connect_to_service: created and initialized dbus connection (process:22576): Gkr-DEBUG: gkr_operation_block_and_unref: 0x1d191e0: blocking request (process:22576): Gkr-DEBUG: item_create_1_unlock_reply: no such default keyring, creating (process:22576): Gkr-DEBUG: gkr_operation_block_and_unref: 0x1d191e0: blocking request (process:22576): Gkr-DEBUG: item_create_1_collection_reply: prompting to create default keyring: /org/freedesktop/secrets/prompt/p5 (process:22576): Gkr-DEBUG: gkr_operation_prompt: 0x1d191e0: calling prompt method (process:22576): Gkr-DEBUG: gkr_operation_block_and_unref: 0x1d191e0: blocking request (process:22576): Gkr-DEBUG: gkr_operation_block_and_unref: 0x1d191e0: blocking on prompt
Seems something is broken with accessing the default keyring? A working build (from commit a8862f7) produced these logs: With the daemon not running (which caused an unlock prompt): (process:21401): Gkr-DEBUG: item_create_start: unlocking the keyring: /org/freedesktop/secrets/aliases/default (process:21401): Gkr-DEBUG: gkr_operation_new: 0x8341e0 (process:21401): Gkr-DEBUG: gkr_operation_block_and_unref: 0x8341e0: processing (process:21401): Gkr-DEBUG: connect_to_service: created and initialized dbus connection (process:21401): Gkr-DEBUG: gkr_operation_block_and_unref: 0x8341e0: blocking request (process:21401): Gkr-DEBUG: item_create_1_unlock_reply: prompting to unlock the keyring: /org/freedesktop/secrets/prompt/u1 (process:21401): Gkr-DEBUG: gkr_operation_prompt: 0x8341e0: calling prompt method (process:21401): Gkr-DEBUG: gkr_operation_block_and_unref: 0x8341e0: blocking request (process:21401): Gkr-DEBUG: gkr_operation_block_and_unref: 0x8341e0: blocking on prompt (process:21401): Gkr-DEBUG: on_prompt_signal: 0x8341e0: prompt was completed (process:21401): Gkr-DEBUG: item_create_1_unlock_prompt_reply: keyring unlocked (process:21401): Gkr-DEBUG: item_create_2_session_request: requesting session (process:21401): Gkr-DEBUG: on_prompt_completed: 0x8341e0 (process:21401): Gkr-DEBUG: gkr_operation_block_and_unref: 0x8341e0: blocking request (process:21401): Gkr-DEBUG: item_create_2_session_reply: have session, encoding secret (process:21401): Gkr-DEBUG: item_create_2_session_reply: creating item (process:21401): Gkr-DEBUG: gkr_operation_block_and_unref: 0x8341e0: blocking request (process:21401): Gkr-DEBUG: item_create_3_created_reply: new item id 122 for path /org/freedesktop/secrets/aliases/default/122 (process:21401): Gkr-DEBUG: gkr_operation_block_and_unref: 0x8341e0: done (process:21401): Gkr-DEBUG: operation_clear_callbacks: 0x8341e0 (process:21401): Gkr-DEBUG: operation_unref: 0x8341e0: freeing Afterwards: (process:21498): Gkr-DEBUG: item_create_start: unlocking the keyring: /org/freedesktop/secrets/aliases/default (process:21498): Gkr-DEBUG: gkr_operation_new: 0x12891e0 (process:21498): Gkr-DEBUG: gkr_operation_block_and_unref: 0x12891e0: processing (process:21498): Gkr-DEBUG: connect_to_service: created and initialized dbus connection (process:21498): Gkr-DEBUG: gkr_operation_block_and_unref: 0x12891e0: blocking request (process:21498): Gkr-DEBUG: item_create_1_unlock_reply: unlocked keyring (process:21498): Gkr-DEBUG: item_create_2_session_request: requesting session (process:21498): Gkr-DEBUG: gkr_operation_block_and_unref: 0x12891e0: blocking request (process:21498): Gkr-DEBUG: item_create_2_session_reply: have session, encoding secret (process:21498): Gkr-DEBUG: item_create_2_session_reply: creating item (process:21498): Gkr-DEBUG: gkr_operation_block_and_unref: 0x12891e0: blocking request (process:21498): Gkr-DEBUG: item_create_3_created_reply: new item id 123 for path /org/freedesktop/secrets/aliases/default/123 (process:21498): Gkr-DEBUG: gkr_operation_block_and_unref: 0x12891e0: done (process:21498): Gkr-DEBUG: operation_clear_callbacks: 0x12891e0 (process:21498): Gkr-DEBUG: operation_unref: 0x12891e0: freeing
Git bisected to c459da1c (Port gnome-keyring-daemon to GDBus).
Comparing DBus interaction for the 3.16 and 3.18 daemon without kdbus, I so far noted the following things: If the daemon isn't running, upon activation the 3.18 daemon claims the bus name before the object tree is ready, resulting in the activating method call failing (No such interface 'org.freedesktop.Secret.Service' on object at path /org/freedesktop/secrets"). This is an additional bug. Shouldn't the code be using g_bus_own_name instead of fiddling with GDBusConnections and RequestName? The (aoo) reply to the first org.freedesktop.secrets.Unlock call with argument (["/org/freedesktop/secrets/aliases/default"]) is ([], "/org/freedesktop/secrets/prompt/u1") for 3.16 and ([], "/") for 3.18.
Created attachment 312757 [details] [review] dbus: Initialize secret service before claiming name Fixes the activation race, but not the broken credentials storing.
I noticed that GKD complains: ** (gnome-keyring-daemon:28779): WARNING **: could not register secret unlock prompt on session bus: An object is already exported for the interface org.freedesktop.Secret.Prompt at /org/freedesktop/secrets/prompt/p1 Unlocking '/org/freedesktop/secrets/collection/login' GkdSecretUnlock exports in its constructor. Apparently code (from GdkSecretCreate?) tries to reuse this path for a new, concurrent GdkSecretUnlock, which fails.
Cosimo. This is a change in the GDBus port. Could you review it?
Stef, I'll try and take a look soon.
Comment on attachment 312757 [details] [review] dbus: Initialize secret service before claiming name Attachment 312757 [details] pushed as 3cf744f - dbus: Initialize secret service before claiming name
This one looks good, and I pushed it to master. Thanks. I will find some time to investigate the other issues later, if no one else beats me at it.
3.18.1 is still buggy.
> 3.18.1 is still buggy. That's an undescriptive comment low on information. But I'll try and be helpful: You may be experiencing bug #756032, which is being merged now and that fix should be 3.18.2
One of Debian users says that he is still having problems, with the latest packages (which correspond to post-3.18.1 Git snapshot, e53af4d55052b879): https://bugs.debian.org/800617#110
The problem still exists in 3.18.2. The first notable difference in behavior from 3.16.0 is the missing object path in the reply to the Unlock call. 3.16.0: ‣ Type=method_call Endian=l Flags=0 Version=1 Priority=0 Cookie=4 Sender=:1.1952 Destination=org.freedesktop.secrets Path=/org/freedesktop/secrets Interface=org.freedesktop.Secret.Service Member=Unlock UniqueName=:1.1952 MESSAGE "ao" { ARRAY "o" { OBJECT_PATH "/org/freedesktop/secrets/aliases/default"; }; }; ‣ Type=method_return Endian=l Flags=1 Version=1 Priority=0 Cookie=102 ReplyCookie=4 Sender=:1.1947 Destination=:1.1952 UniqueName=:1.1947 MESSAGE "aoo" { ARRAY "o" { OBJECT_PATH "/org/freedesktop/secrets/aliases/default"; }; OBJECT_PATH "/"; }; 3.18.2: ‣ Type=method_call Endian=l Flags=0 Version=1 Priority=0 Cookie=4 Sender=:1.1961 Destination=org.freedesktop.secrets Path=/org/freedesktop/secrets Interface=org.freedesktop.Secret.Service Member=Unlock UniqueName=:1.1961 MESSAGE "ao" { ARRAY "o" { OBJECT_PATH "/org/freedesktop/secrets/aliases/default"; }; }; ‣ Type=method_return Endian=l Flags=1 Version=1 Priority=0 Cookie=90 ReplyCookie=4 Sender=:1.1955 Destination=:1.1961 UniqueName=:1.1955 MESSAGE "aoo" { ARRAY "o" { }; OBJECT_PATH "/"; }; This is followed by OpenSession for 3.16.0 and CreateCollection for 3.18.2.
I think this is a dulpicate of #756865 Please reopen if that's not the case. *** This bug has been marked as a duplicate of bug 756865 ***