gpg-agent prompt slow to show up

Charlie Brown stieizc.33 at gmail.com
Sat Nov 28 04:33:34 CET 2015


> I have yet to be able to replicate this myself, but i've seen other
> people have this problem when they're using pinentry-gtk-2 or
> pinentry-gnome3 and they have something wrong with their dbus setup
> related to localization (l10n) or accessibility (a11y).
>
> In particular, there appears to be a 25000 millisecond (25 second)
> timeout in some gtk frameworks while trying to look for the dbus service
> named "org.a11y.Bus".

Thank you for pointing to dbus, that is a good place to find out what
happens. And you are right, I'm using pinentry-gnome3 and there's a 25
second gap between
------------
method call time=1448678135.935348 sender=:1.30 ->
destination=org.a11y.Bus serial=2 path=/org/a11y/bus;
interface=org.a11y.Bus; member=GetAddress
method call time=1448678160.965303 sender=:1.31 ->
destination=org.freedesktop.DBus serial=1 path=/org/freedesktop/DBus;
interface=org.freedesktop.DBus; member=Hello
-------------

And for me, there's *another* 25 second gap between
-------------
signal time=1448678160.983489 sender=org.freedesktop.DBus ->
destination=(null destination) serial=101 path=/org/freedesktop/DBus;
interface=org.freedesktop.DBus; member=NameOwnerChanged
   string ":1.32"
   string ":1.32"
   string ""
signal time=1448678185.987561 sender=org.freedesktop.DBus ->
destination=:1.31 serial=6 path=/org/freedesktop/DBus;
interface=org.freedesktop.DBus; member=NameLost
   string ":1.31"
-------------
So it's not 15 seconds, it's 50 seconds in all. I wish I had timed
this. If anyone is interested, the output from `dbus-monitor` between
a gpg command was triggered and the passphrase prompt showed up is
attached as `dbus-gpg.log`.

> On the (debian unstable) machine of my colleague where we tracked it
> down this much, the problem was resolved after reinstalling
> at-spi2-core, but it didn't return after we removed it again.

I removed at-spi2-core and save 25 seconds. But that's not a perfect solution.

Then I look deeper into the gnome-keyring bug. I removed ssh, pkcs11
and secret autostart for gnome-keyring in /etc/xdg/autostart (the
gnome-keyring-daemon still get launched by pam), and found that in the
first time the prompt showed up quickly (and the dbus log is attached
as `dbus-gpg-1.log`, that one still has the a11y problem), but
following ones have the same problem. I'm not familiar with dbus, but
comparing the two logs, it appears to me that gnome-keyring is setting
'org.gnome.keyring' to empty string. If anyone have seen the same
problem, please help me.

It seems that none of these two bugs is related to GnuPG. I will send
emails to a11y and gnome-keyring and see if they have any idea.

Thanks for your help!

Sincerely,
王文鑫
Wenxin Wang
-------------- next part --------------
method call time=1448678135.934762 sender=:1.30 -> destination=org.freedesktop.DBus serial=1 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=Hello
method return time=1448678135.934793 sender=org.freedesktop.DBus -> destination=:1.30 serial=1 reply_serial=1
   string ":1.30"
signal time=1448678135.934808 sender=org.freedesktop.DBus -> destination=(null destination) serial=98 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
   string ":1.30"
   string ""
   string ":1.30"
signal time=1448678135.934826 sender=org.freedesktop.DBus -> destination=:1.30 serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameAcquired
   string ":1.30"
method call time=1448678135.935348 sender=:1.30 -> destination=org.a11y.Bus serial=2 path=/org/a11y/bus; interface=org.a11y.Bus; member=GetAddress
method call time=1448678160.965303 sender=:1.31 -> destination=org.freedesktop.DBus serial=1 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=Hello
method return time=1448678160.965342 sender=org.freedesktop.DBus -> destination=:1.31 serial=1 reply_serial=1
   string ":1.31"
signal time=1448678160.965365 sender=org.freedesktop.DBus -> destination=(null destination) serial=99 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
   string ":1.31"
   string ""
   string ":1.31"
signal time=1448678160.965392 sender=org.freedesktop.DBus -> destination=:1.31 serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameAcquired
   string ":1.31"
method call time=1448678160.968097 sender=:1.31 -> destination=org.freedesktop.DBus serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=AddMatch
   string "type='signal',sender='org.freedesktop.secrets',interface='org.freedesktop.DBus.Properties',member='PropertiesChanged',path='/org/freedesktop/secrets',arg0='org.freedesktop.Secret.Service'"
method return time=1448678160.968151 sender=org.freedesktop.DBus -> destination=:1.31 serial=3 reply_serial=2
method call time=1448678160.968170 sender=:1.31 -> destination=org.freedesktop.DBus serial=3 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=AddMatch
   string "type='signal',sender='org.freedesktop.secrets',interface='org.freedesktop.Secret.Service',path='/org/freedesktop/secrets'"
method return time=1448678160.968194 sender=org.freedesktop.DBus -> destination=:1.31 serial=4 reply_serial=3
method call time=1448678160.968210 sender=:1.31 -> destination=org.freedesktop.DBus serial=4 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=AddMatch
   string "type='signal',sender='org.freedesktop.DBus',interface='org.freedesktop.DBus',member='NameOwnerChanged',path='/org/freedesktop/DBus',arg0='org.freedesktop.secrets'"
method return time=1448678160.968233 sender=org.freedesktop.DBus -> destination=:1.31 serial=5 reply_serial=4
method call time=1448678160.968252 sender=:1.31 -> destination=org.freedesktop.DBus serial=5 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=StartServiceByName
   string "org.freedesktop.secrets"
   uint32 0
method call time=1448678160.979902 sender=:1.32 -> destination=org.freedesktop.DBus serial=1 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=Hello
method return time=1448678160.980018 sender=org.freedesktop.DBus -> destination=:1.32 serial=1 reply_serial=1
   string ":1.32"
signal time=1448678160.980291 sender=org.freedesktop.DBus -> destination=(null destination) serial=100 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
   string ":1.32"
   string ""
   string ":1.32"
signal time=1448678160.980475 sender=org.freedesktop.DBus -> destination=:1.32 serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameAcquired
   string ":1.32"
method call time=1448678160.981071 sender=:1.32 -> destination=org.freedesktop.DBus serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=AddMatch
   string "type='signal',sender='org.freedesktop.DBus',interface='org.freedesktop.DBus',member='NameOwnerChanged',path='/org/freedesktop/DBus',arg0='org.gnome.keyring'"
method return time=1448678160.981257 sender=org.freedesktop.DBus -> destination=:1.32 serial=3 reply_serial=2
method call time=1448678160.981497 sender=:1.32 -> destination=org.freedesktop.DBus serial=3 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=GetNameOwner
   string "org.gnome.keyring"
error time=1448678160.981662 sender=org.freedesktop.DBus -> destination=:1.32 error_name=org.freedesktop.DBus.Error.NameHasNoOwner reply_serial=3
   string "Could not get owner of name 'org.gnome.keyring': no such name"
signal time=1448678160.983432 sender=org.freedesktop.DBus -> destination=:1.32 serial=5 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameLost
   string ":1.32"
signal time=1448678160.983489 sender=org.freedesktop.DBus -> destination=(null destination) serial=101 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
   string ":1.32"
   string ":1.32"
   string ""
signal time=1448678185.987561 sender=org.freedesktop.DBus -> destination=:1.31 serial=6 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameLost
   string ":1.31"
signal time=1448678185.987623 sender=org.freedesktop.DBus -> destination=(null destination) serial=102 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
   string ":1.31"
   string ":1.31"
   string ""
method call time=1448678185.989570 sender=:1.33 -> destination=org.freedesktop.DBus serial=1 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=Hello
method return time=1448678185.989608 sender=org.freedesktop.DBus -> destination=:1.33 serial=1 reply_serial=1
   string ":1.33"
signal time=1448678185.989634 sender=org.freedesktop.DBus -> destination=(null destination) serial=103 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
   string ":1.33"
   string ""
   string ":1.33"
signal time=1448678185.989668 sender=org.freedesktop.DBus -> destination=:1.33 serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameAcquired
   string ":1.33"
method call time=1448678185.990746 sender=:1.33 -> destination=org.freedesktop.DBus serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=AddMatch
   string "type='signal',sender='org.freedesktop.DBus',interface='org.freedesktop.DBus',member='NameOwnerChanged',path='/org/freedesktop/DBus',arg0='org.gnome.keyring.SystemPrompter'"
method return time=1448678185.990794 sender=org.freedesktop.DBus -> destination=:1.33 serial=3 reply_serial=2
method call time=1448678185.990811 sender=:1.33 -> destination=org.freedesktop.DBus serial=3 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=GetNameOwner
   string "org.gnome.keyring.SystemPrompter"
error time=1448678185.990834 sender=org.freedesktop.DBus -> destination=:1.33 error_name=org.freedesktop.DBus.Error.NameHasNoOwner reply_serial=3
   string "Could not get owner of name 'org.gnome.keyring.SystemPrompter': no such name"
method call time=1448678185.991727 sender=:1.33 -> destination=org.gnome.keyring.SystemPrompter serial=4 path=/org/gnome/keyring/Prompter; interface=org.gnome.keyring.internal.Prompter; member=BeginPrompting
   object path "/org/gnome/keyring/Prompt/p0"
method call time=1448678186.036967 sender=:1.34 -> destination=org.freedesktop.DBus serial=1 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=Hello
method return time=1448678186.037002 sender=org.freedesktop.DBus -> destination=:1.34 serial=1 reply_serial=1
   string ":1.34"
signal time=1448678186.037024 sender=org.freedesktop.DBus -> destination=(null destination) serial=104 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
   string ":1.34"
   string ""
   string ":1.34"
signal time=1448678186.037049 sender=org.freedesktop.DBus -> destination=:1.34 serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameAcquired
   string ":1.34"
method call time=1448678186.039034 sender=:1.34 -> destination=org.freedesktop.DBus serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=RequestName
   string "org.gnome.keyring.SystemPrompter"
   uint32 2
signal time=1448678186.039072 sender=org.freedesktop.DBus -> destination=(null destination) serial=5 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
   string "org.gnome.keyring.SystemPrompter"
   string ""
   string ":1.34"
signal time=1448678186.039094 sender=org.freedesktop.DBus -> destination=:1.34 serial=3 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameAcquired
   string "org.gnome.keyring.SystemPrompter"
method return time=1448678186.039109 sender=org.freedesktop.DBus -> destination=:1.34 serial=4 reply_serial=2
   uint32 1
method call time=1448678186.039787 sender=:1.34 -> destination=org.freedesktop.DBus serial=3 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=RequestName
   string "org.gnome.keyring.PrivatePrompter"
   uint32 2
signal time=1448678186.039820 sender=org.freedesktop.DBus -> destination=(null destination) serial=105 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
   string "org.gnome.keyring.PrivatePrompter"
   string ""
   string ":1.34"
signal time=1448678186.039842 sender=org.freedesktop.DBus -> destination=:1.34 serial=5 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameAcquired
   string "org.gnome.keyring.PrivatePrompter"
method return time=1448678186.039856 sender=org.freedesktop.DBus -> destination=:1.34 serial=6 reply_serial=3
   uint32 1
method call time=1448678186.042777 sender=:1.34 -> destination=org.freedesktop.DBus serial=4 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=AddMatch
   string "type='signal',sender='org.freedesktop.DBus',interface='org.freedesktop.DBus',member='NameOwnerChanged',path='/org/freedesktop/DBus',arg0=':1.33'"
method return time=1448678186.042812 sender=org.freedesktop.DBus -> destination=:1.34 serial=7 reply_serial=4
method call time=1448678186.042823 sender=:1.34 -> destination=org.freedesktop.DBus serial=5 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=GetNameOwner
   string ":1.33"
method return time=1448678186.042838 sender=org.freedesktop.DBus -> destination=:1.34 serial=8 reply_serial=5
   string ":1.33"
method return time=1448678186.042849 sender=:1.34 -> destination=:1.33 serial=6 reply_serial=4
method call time=1448678186.146370 sender=:1.34 -> destination=:1.33 serial=7 path=/org/gnome/keyring/Prompt/p0; interface=org.gnome.keyring.internal.Prompter.Callback; member=PromptReady
   string ""
   array [
   ]
   string "[sx-aes-1]
public=IcgJc2BRt0Li6WPTkkIarcv4DDICq7LvUdGdk7TH3gVm7YRoVxSPzud2lvvUURQYT7XXaaKk/rpWmxuMn7rg6Okn+KSHmvMDjVRrNIUDKiG/hlgk/Asno5o8c0mtN+pB6BiP3VnttC7WhE14PofLuCKdEmohu/bOG0p98QatTnM1tE8ssdiCrPlO0OPRpyADFmya2H8FJ33r+uMdfipTW1ufLoZlMGEDkIi7+cIv6yV4B0lsRgzLqQ2sELRCgsmp
"
method return time=1448678186.147439 sender=:1.33 -> destination=:1.34 serial=5 reply_serial=7
method call time=1448678186.160833 sender=:1.33 -> destination=org.freedesktop.DBus serial=6 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=RemoveMatch
   string "type='signal',sender='org.freedesktop.DBus',interface='org.freedesktop.DBus',member='NameOwnerChanged',path='/org/freedesktop/DBus',arg0='org.gnome.keyring.SystemPrompter'"
method return time=1448678186.160852 sender=org.freedesktop.DBus -> destination=:1.33 serial=6 reply_serial=6
method call time=1448678186.161014 sender=:1.33 -> destination=org.freedesktop.DBus serial=7 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=AddMatch
   string "type='signal',sender='org.freedesktop.DBus',interface='org.freedesktop.DBus',member='NameOwnerChanged',path='/org/freedesktop/DBus',arg0='org.gnome.keyring.SystemPrompter'"
method return time=1448678186.161026 sender=org.freedesktop.DBus -> destination=:1.33 serial=7 reply_serial=7
method call time=1448678186.161245 sender=:1.33 -> destination=org.freedesktop.DBus serial=8 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=GetNameOwner
   string "org.gnome.keyring.SystemPrompter"
method return time=1448678186.161257 sender=org.freedesktop.DBus -> destination=:1.33 serial=8 reply_serial=8
   string ":1.34"
method call time=1448678186.161264 sender=:1.33 -> destination=org.gnome.keyring.SystemPrompter serial=9 path=/org/gnome/keyring/Prompter; interface=org.gnome.keyring.internal.Prompter; member=PerformPrompt
   object path "/org/gnome/keyring/Prompt/p0"
   string "password"
   array [
      dict entry(
         string "caller-window"
         variant             string ""
      )
      dict entry(
         string "cancel-label"
         variant             string "_Cancel"
      )
      dict entry(
         string "message"
         variant             string "Passphrase:"
      )
      dict entry(
         string "title"
         variant             string ""
      )
      dict entry(
         string "choice-label"
         variant             string "_Save in password manager"
      )
      dict entry(
         string "warning"
         variant             string ""
      )
      dict entry(
         string "description"
         variant             string "You need a passphrase to unlock the secret key for user:
"Wenxin Wang (Charlie Brown) <stieizc.33 at gmail.com>"
4096-bit RSA key, ID DF86FCC1, created 2015-11-24 (main key ID 76D23BD4)
"
      )
      dict entry(
         string "continue-label"
         variant             string "_OK"
      )
      dict entry(
         string "password-new"
         variant             boolean false
      )
   ]
   string "[sx-aes-1]
public=59nhv7KQ4x6Wz6F/t5mbMLVGh9hyRi4JYpAiCn0JK2iwKOxCnKrIrPOx5tmAc20reOI20029laWTaDYGNZF/yvgqnZCbgqQnjovdjLCkJPsqhVBqdKXqeWFCNtpt/MaCGvmGy8VVww09waPzCSJyuhnJAi1TrP4VTFY6gEAqyNrvxZorfSYswbOGQiTN7QJ0bS/FNwFglGNkIlOrVwEAoY5uU9beCNzgW1q5xkHxucMJLGLKQT4zoE9wITK3t3bf
"
method return time=1448678186.202715 sender=:1.34 -> destination=:1.33 serial=8 reply_serial=9


More information about the Gnupg-users mailing list