pinentry-{qt,gtk2,gnome3} stopped working pinentry-fltk works, why?

Mon Dec 21 11:47:43 CET 2020

Dear gnupg users, since Friday pinentry-{qt,gtk2,gnome3}
stopped working.  When I want to decrypt some .gpg file, no dialog
appears and gpg-agent times out.  Luckily pinentry-curses and
pinentry-fltk still do work.

This is on a debian buster system with gpg* packages from backports,
pinentry* packages from buster (since there are no backports).

I found the debug-level directive for gpg-agent and set it to expert.
I edited the log, the edited parts are identical between the two sessions.

This is the debug info when using pinentry-flkt, which succeeds:

2020-12-21 11:34:07 gpg-agent[4706] gpg-agent (GnuPG) 2.2.20 starting in supervised mode.
2020-12-21 11:34:07 gpg-agent[4706] using fd 3 for browser socket (/run/user/1000/gnupg/S.gpg-agent.browser)
2020-12-21 11:34:07 gpg-agent[4706] using fd 4 for ssh socket (/run/user/1000/gnupg/S.gpg-agent.ssh)
2020-12-21 11:34:07 gpg-agent[4706] using fd 5 for extra socket (/run/user/1000/gnupg/S.gpg-agent.extra)
2020-12-21 11:34:07 gpg-agent[4706] using fd 6 for std socket (/run/user/1000/gnupg/S.gpg-agent)
2020-12-21 11:34:07 gpg-agent[4706] listening on: std=6 extra=5 browser=3 ssh=4
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK Pleased to meet you, process 4704
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- RESET
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- OPTION ttyname=/dev/pts/8
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- OPTION ttytype=screen-256color-bce-s
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- OPTION display=:0
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- OPTION xauthority=/home/grfz/.Xauthority
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- OPTION putenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- OPTION lc-ctype=de_DE.utf8
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- OPTION lc-messages=C
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- GETINFO version
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> D 2.2.20
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- OPTION allow-pinentry-notify
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- OPTION agent-awareness=2.1.0
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- HAVEKEY xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- HAVEKEY xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- HAVEKEY xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- RESET
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- SETKEY xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- SETKEYDESC Please+enter+the+passphrase+to+unlock+the+OpenPGP+secret+key:%0A%22Gregor+Zattler+(do+not+use+texmex at uni.de+any+more)+<telegraph at gmx.net>%22%0A4096-bit+ELG+key,+ID+0xAD8A61F5F877E5F0,%0Acreated+2001-09-29+(main+key+ID+0xF2EB825AD25307CA).%0A
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- PKDECRYPT
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> S INQUIRE_MAXLEN 4096
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> INQUIRE CIPHERTEXT
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- [ xx xx xx xx xx xx xx xx xx xx xx xx xx xx xx xx ...(982 byte(s) skipped) ]
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- [ xx xx xx xx xx xx xx xx xx xx xx xx xx xx xx xx ...(84 byte(s) skipped) ]
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- END
2020-12-21 11:34:07 gpg-agent[4706] DBG: agent_get_cache 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'.0 (mode 2) ...
2020-12-21 11:34:07 gpg-agent[4706] DBG: ... miss
2020-12-21 11:34:07 gpg-agent[4706] starting a new PIN Entry
2020-12-21 11:34:07 gpg-agent[4706] DBG: connection to PIN entry established
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 -> INQUIRE PINENTRY_LAUNCHED 4708 fltk 1.1.0 /dev/pts/8 screen-256color-bce-s :0
2020-12-21 11:34:07 gpg-agent[4706] DBG: chan_10 <- END
2020-12-21 11:34:20 gpg-agent[4706] DBG: agent_put_cache 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'.0 (mode 2) requested ttl=0
2020-12-21 11:34:20 gpg-agent[4706] DBG: chan_10 -> [ xx xx xx xx xx xx xx xx xx xx xx xx xx xx xx xx ...(517 byte(s) skipped) ]
2020-12-21 11:34:20 gpg-agent[4706] DBG: chan_10 -> OK
2020-12-21 11:34:20 gpg-agent[4706] DBG: chan_10 <- [eof]

2020-12-21 11:34:47 gpg-agent[4706] SIGTERM received - shutting down ...
2020-12-21 11:34:47 gpg-agent[4706] gpg-agent (GnuPG) 2.2.20 stopped

This is the debug info when using pinentry-qt, which fails:

2020-12-21 11:35:02 gpg-agent[5108] gpg-agent (GnuPG) 2.2.20 starting in supervised mode.
2020-12-21 11:35:02 gpg-agent[5108] using fd 3 for browser socket (/run/user/1000/gnupg/S.gpg-agent.browser)
2020-12-21 11:35:02 gpg-agent[5108] using fd 4 for ssh socket (/run/user/1000/gnupg/S.gpg-agent.ssh)
2020-12-21 11:35:02 gpg-agent[5108] using fd 5 for extra socket (/run/user/1000/gnupg/S.gpg-agent.extra)
2020-12-21 11:35:02 gpg-agent[5108] using fd 6 for std socket (/run/user/1000/gnupg/S.gpg-agent)
2020-12-21 11:35:02 gpg-agent[5108] listening on: std=6 extra=5 browser=3 ssh=4
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK Pleased to meet you, process 5106
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- RESET
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- OPTION ttyname=/dev/pts/8
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- OPTION ttytype=screen-256color-bce-s
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- OPTION display=:0
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- OPTION xauthority=/home/grfz/.Xauthority
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- OPTION putenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- OPTION lc-ctype=de_DE.utf8
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- OPTION lc-messages=C
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- GETINFO version
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> D 2.2.20
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- OPTION allow-pinentry-notify
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- OPTION agent-awareness=2.1.0
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- HAVEKEY xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- HAVEKEY xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- HAVEKEY xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- RESET
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- SETKEY xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- SETKEYDESC Please+enter+the+passphrase+to+unlock+the+OpenPGP+secret+key:%0A%22Gregor+Zattler+(do+not+use+texmex at uni.de+any+more)+<telegraph at gmx.net>%22%0A4096-bit+ELG+key,+ID+0xAD8A61F5F877E5F0,%0Acreated+2001-09-29+(main+key+ID+0xF2EB825AD25307CA).%0A
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> OK
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- PKDECRYPT
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> S INQUIRE_MAXLEN 4096
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> INQUIRE CIPHERTEXT
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- [ xx xx xx xx xx xx xx xx xx xx xx xx xx xx xx xx ...(982 byte(s) skipped) ]
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- [ xx xx xx xx xx xx xx xx xx xx xx xx xx xx xx xx ...(84 byte(s) skipped) ]
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- END
2020-12-21 11:35:02 gpg-agent[5108] DBG: agent_get_cache 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'.0 (mode 2) ...
2020-12-21 11:35:02 gpg-agent[5108] DBG: ... miss
2020-12-21 11:35:02 gpg-agent[5108] starting a new PIN Entry
2020-12-21 11:35:02 gpg-agent[5108] DBG: connection to PIN entry established
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 -> INQUIRE PINENTRY_LAUNCHED 5110 qt 1.1.0 /dev/pts/8 screen-256color-bce-s :0
2020-12-21 11:35:02 gpg-agent[5108] DBG: chan_10 <- END
2020-12-21 11:36:02 gpg-agent[5108] DBG: error calling pinentry: Timeout <Pinentry>
2020-12-21 11:36:02 gpg-agent[5108] failed to unprotect the secret key: Timeout
2020-12-21 11:36:02 gpg-agent[5108] failed to read the secret key
2020-12-21 11:36:02 gpg-agent[5108] command 'PKDECRYPT' failed: Timeout <Pinentry>
2020-12-21 11:36:02 gpg-agent[5108] DBG: chan_10 -> ERR 83886142 Timeout <Pinentry>
2020-12-21 11:36:02 gpg-agent[5108] DBG: chan_10 <- [eof]

Any idea who to get pinentry-qt working again?  It simply shows most
of the key uid in question.

Ciao, Gregor
--
 -... --- .-. . -.. ..--.. ...-.-