Page MenuHome GnuPG
Create Task
Maniphest T3240

Pinentry takes long to appear
Closed, InvalidPublic
Actions

Description

Hi,

when I run

echo "Test" | gpg -v -s

it takes about 30 seconds for the password entry popup to appear.
I don't think this is normal.

EDIT: I also tried other pinentry versions (-qt, -curses, etc.) the problem is the same.
I'm willing to provide any additional information needed.

I see this output

gpg: using pgp trust model
gpg: writing to stdout
gpg: pinentry launched (18389 gtk2 1.0.0 ? ? ?)

then it waits a long time.

Details

Version
pinentry 1.0.0

Event Timeline

im0nde created this task.Jun 30 2017, 5:57 PM
jcross updated the task description. (Show Details)Jul 3 2017, 1:55 AM
im0nde updated the task description. (Show Details)Jul 3 2017, 2:20 AM
• werner added a project: Info Needed.Jul 3 2017, 12:56 PM
• werner added a subscriber: • werner.

What version of GnuPG are you using? Standard upstream or from a distribution?

To debug the problem you should enter

log-file /foo/bar/agent.log
debug-pinentry
debug ipc
verbose

into ~/.gnupg/gpg-agent.conf and restart the agent ("pkill gpg-agent" or "gpgconf --kill gpg-agent")

im0nde added a comment.Jul 3 2017, 1:07 PM
❯ gpg --version                                                               ⏎
gpg (GnuPG) 2.1.21
libgcrypt 1.7.8
Copyright (C) 2017 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <https://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.

Home: /home/binaryplease/.gnupg
Supported algorithms:
Pubkey: RSA, ELG, DSA, ECDH, ECDSA, EDDSA
Cipher: IDEA, 3DES, CAST5, BLOWFISH, AES, AES192, AES256, TWOFISH,
        CAMELLIA128, CAMELLIA192, CAMELLIA256
Hash: SHA1, RIPEMD160, SHA256, SHA384, SHA512, SHA224
Compression: Uncompressed, ZIP, ZLIB, BZIP2

Installed via Archlinux package manager, everything up-to-date.

I updated the file as described, it now looks like this:

default-cache-ttl 300
max-cache-ttl 10800
pinentry-program /usr/bin/pinentry-qt
log-file /home/binaryplease/agent.log
debug-pinentry
debug ipc
verbose

and re-run the echo comamnd above. Same wait time after the line "
gpg: pinentry launched (11048 qt 1.0.0 ? ? ?)" is printed to console.

This is the output in the log file (edited to remove any potetion security relevant info:

 cat agent.log
2017-07-03 13:00:39 gpg-agent[11043] gpg-agent (GnuPG) 2.1.21 starting in supervised mode.
2017-07-03 13:00:39 gpg-agent[11043] using fd 3 for browser socket (/run/user/1000/gnupg/S.gpg-agent.browser)
2017-07-03 13:00:39 gpg-agent[11043] using fd 4 for extra socket (/run/user/1000/gnupg/S.gpg-agent.extra)
2017-07-03 13:00:39 gpg-agent[11043] using fd 5 for ssh socket (/run/user/1000/gnupg/S.gpg-agent.ssh)
2017-07-03 13:00:39 gpg-agent[11043] using fd 6 for std socket (/run/user/1000/gnupg/S.gpg-agent)
2017-07-03 13:00:39 gpg-agent[11043] listening on: std=6 extra=4 browser=3 ssh=5
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK Pleased to meet you, process 11042
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- RESET
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- OPTION ttytype=xterm-termite
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- OPTION display=:0
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- OPTION xauthority=/home/binaryplease/.Xauthority
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- OPTION putenv=DBUS_SESSION_BUS_ADDRESS=unix:abstract=/tmp/dbus-FeEjufhZ9r,guid=********************************
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- GETINFO version
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> D 2.1.21
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- OPTION allow-pinentry-notify
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- OPTION agent-awareness=2.1.0
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- SCD GETINFO version
2017-07-03 13:00:39 gpg-agent[11043] no running SCdaemon - starting it
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_10 <- OK GNU Privacy Guard's Smartcard server ready
2017-07-03 13:00:39 gpg-agent[11043] DBG: first connection to SCdaemon established
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_10 -> GETINFO socket_name
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_10 <- D /run/user/1000/gnupg/S.scdaemon
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_10 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: additional connections at '/run/user/1000/gnupg/S.scdaemon'
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_10 -> OPTION event-signal=12
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_10 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_10 -> GETINFO version
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_10 <- D 2.1.21
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_10 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> D 2.1.21
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- SCD SERIALNO openpgp
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_10 -> SERIALNO openpgp
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_10 <- ERR 100696144 No such device <SCD>
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> ERR 100696144 No such device <SCD>
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- HAVEKEY **************************************** *****************************************
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- KEYINFO ****************************************
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> S KEYINFO **************************************** D - - - P - - -
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- RESET
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- SIGKEY C04*************************************
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- SETKEYDESC Please+enter+the+passphrase+to+unlock+the+OpenPGP+secret+key:%0A%22**my**+**name**+**here**+<**my email here**>%22%0A2048-bit+RSA+key,+ID+***************,%0Acreated+2014-05-09.%0A
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- SETHASH 8 ****************************************************************
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- PKSIGN
2017-07-03 13:00:39 gpg-agent[11043] starting a new PIN Entry
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK Pleased to meet you, process 11043
2017-07-03 13:00:39 gpg-agent[11043] DBG: connection to PIN entry established
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> OPTION grab
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> OPTION ttytype=xterm-termite
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> OPTION allow-external-password-cache
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> OPTION default-ok=_OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> OPTION default-cancel=_Cancel
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> OPTION default-yes=_Yes
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- ERR 83886254 Unknown option <Pinentry>
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> OPTION default-no=_No
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- ERR 83886254 Unknown option <Pinentry>
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> OPTION default-prompt=PIN:
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> OPTION default-pwmngr=_Save in password manager
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> OPTION default-cf-visi=Do you really want to make your passphrase visible on the screen?
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> OPTION default-tt-visi=Make passphrase visible
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> OPTION default-tt-hide=Hide passphrase
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> OPTION touch-file=/run/user/1000/gnupg/S.gpg-agent
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> OPTION owner=11042 binaryplease-laptop
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- ERR 83886254 Unknown option <Pinentry>
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> GETINFO flavor
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- D qt
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> GETINFO version
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- D 1.0.0
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> GETINFO ttyinfo
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- ERR 83886360 IPC parameter error <Pinentry>
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> GETINFO pid
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- D 11048
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 -> INQUIRE PINENTRY_LAUNCHED 11048 qt 1.0.0 ? ? ?
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_9 <- END
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> SETKEYINFO n/****************************************
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> SETDESC Please enter the passphrase to unlock the OpenPGP secret key:%0A%22*******************************************************%22%0A2048-bit RSA key, ID ****************,%0Acreated 2014-05-09.%0A
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> SETPROMPT Passphrase:
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 <- OK
2017-07-03 13:00:39 gpg-agent[11043] DBG: chan_11 -> [[Confidential data not shown]]
2017-07-03 13:01:08 gpg-agent[11043] DBG: chan_11 <- [[Confidential data not shown]]
2017-07-03 13:01:08 gpg-agent[11043] DBG: chan_11 <- [[Confidential data not shown]]
2017-07-03 13:01:08 gpg-agent[11043] DBG: chan_11 -> BYE
2017-07-03 13:01:08 gpg-agent[11043] DBG: chan_9 -> [ 44 20 28 37 3a 73 69 67 2d 76 61 6c 28 33 3a 72 ...(271 byte(s) skipped) ]
2017-07-03 13:01:08 gpg-agent[11043] DBG: chan_9 -> OK
2017-07-03 13:01:08 gpg-agent[11043] DBG: chan_9 <- [eof]
2017-07-03 13:01:08 gpg-agent[11043] DBG: chan_10 -> RESTART
2017-07-03 13:01:08 gpg-agent[11043] DBG: chan_10 <- OK
im0nde added a comment.Jul 3 2017, 2:24 PM

Addition:

when I run tail -f agent,log while executing the echo command these are the last lines that are printed to the file before the wait:

2017-07-03 14:24:26 gpg-agent[21440] DBG: chan_11 <- OK
2017-07-03 14:24:26 gpg-agent[21440] DBG: chan_11 -> SETPROMPT Passphrase:
2017-07-03 14:24:26 gpg-agent[21440] DBG: chan_11 <- OK
2017-07-03 14:24:26 gpg-agent[21440] DBG: chan_11 -> [[Confidential data not shown]]
im0nde added a comment.Jul 3 2017, 2:47 PM

Addition 2 [Workaround]:

I have now uninstalled gnome-keyring.
The problem does not appear anymore.

Neverthenless, I would be interested in other solutions that allow me to keep gnome-keyring installed alongside, as I would like to use it for other applications.

• werner removed a project: Info Needed.Jul 4 2017, 10:15 AM
justus closed this task as Invalid.Jul 11 2017, 2:38 PM
justus claimed this task.
justus added a subscriber: justus.
In T3240#99654, @im0nde wrote:

Neverthenless, I would be interested in other solutions that allow me to keep gnome-keyring installed alongside, as I would like to use it for other applications.

The delay is caused by the pinentry querying the GNOME keyring. Add no-allow-external-cache to your gpg-agent.conf, or fix your GNOME installation, or report the problem to the GNOME people.