Failed to export secret key

[Alexander Leidinger]

Am 2023-09-05 16:50, schrieb Werner Koch:
> On Mon,  4 Sep 2023 19:45, Alexander Leidinger said:
> 
>> If I specify --pinentry-mode loopback it works. Shouldn't this also
>> work without this option? If yes, what's wrong or how to debug this
> 
> Sure, this shall work.  You may want to add
> 
> --8<---------------cut here---------------start------------->8---
> debug ipc
> debug-pinentry
> log-file /some/file
> --8<---------------cut here---------------end--------------->8---
> 
> to gpg-agent.conf, restart  the agent and check the log file.

The debug log:
---snip---
2023-09-08 13:37:48 gpg-agent[94276] listening on socket 
'/home/netchild/.gnupg/S.gpg-agent'
2023-09-08 13:37:48 gpg-agent[94276] listening on socket 
'/home/netchild/.gnupg/S.gpg-agent.extra'
2023-09-08 13:37:48 gpg-agent[94276] listening on socket 
'/home/netchild/.gnupg/S.gpg-agent.browser'
2023-09-08 13:37:48 gpg-agent[94276] listening on socket 
'/home/netchild/.gnupg/S.gpg-agent.ssh'
2023-09-08 13:37:48 gpg-agent[94491] gpg-agent (GnuPG) 2.4.3 started
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> OK Pleased to meet 
you
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 <- RESET
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> OK
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 <- OPTION 
ttyname=/dev/pts/5
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> OK
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 <- OPTION 
ttytype=tmux-256color
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> OK
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 <- OPTION lc-ctype=C
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> OK
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 <- OPTION lc-messages=C
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> OK
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 <- GETINFO version
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> D 2.4.3
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> OK
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 <- OPTION 
allow-pinentry-notify
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> OK
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 <- OPTION 
agent-awareness=2.1.0
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> OK
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 <- KEYWRAP_KEY --export
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> [[Confidential data 
not shown]]
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> OK
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 <- HAVEKEY --list=1000
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> [ 44 20 2a 2b f8 18 
37 63 7b b2 14 a3 34 4a 2a 5f ...(66 byte(s) skipped) ]
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> OK
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 <- KEYINFO 
89DE8BFC8A2A81F8C9BD2F7940C7373A4DE34E7C
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> S KEYINFO 
89DE8BFC8A2A81F8C9BD2F7940C7373A4DE34E7C D - - - P - - -
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> OK2023-09-08 
13:37:48 gpg-agent[94491] DBG: chan_8 <- SETKEYDESC 
Please+enter+the+passphrase+to+export+the+OpenPGP+secret+key:%0A%22Alexander+Leidinger+<Alexander at Leidinger.net>%22%0A4096-bit+RSA+key,+ID+8F31830F9F2772BF,%0Acreated+2016-08-16.%0A
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 -> OK
2023-09-08 13:37:48 gpg-agent[94491] DBG: chan_8 <- EXPORT_KEY --openpgp 
  89DE8BFC8A2A81F8C9BD2F7940C7373A4DE34E7C
2023-09-08 13:37:48 gpg-agent[94491] starting a new PIN Entry
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK Pleased to meet 
you, process 94491
2023-09-08 13:37:53 gpg-agent[94491] DBG: connection to PIN entry 
established
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION no-grab
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION 
ttyname=/dev/pts/5
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION 
ttytype=tmux-256color
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION lc-ctype=C
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION lc-messages=C
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION 
allow-external-password-cache
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION 
default-ok=_OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION 
default-cancel=_Cancel
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION 
default-yes=_Yes
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- ERR 83886254 Unknown 
option <Pinentry>
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION 
default-no=_No
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- ERR 83886254 Unknown 
option <Pinentry>
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION 
default-prompt=PIN:
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION 
default-pwmngr=_Save in password manager
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION 
default-cf-visi=Do you really want to make your passphrase visible on 
the screen?
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION 
default-tt-visi=Make passphrase visible
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION 
default-tt-hide=Hide passphrase
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION 
default-capshint=Caps Lock is on
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> OPTION 
touch-file=/home/netchild/.gnupg/S.gpg-agent
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> GETINFO flavor
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- D tty
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> GETINFO version
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- D 1.2.1
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> GETINFO ttyinfo
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- D /dev/pts/5 
tmux-256color - ? 1001/1001 0
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> GETINFO pid
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- D 94492
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_8 -> INQUIRE 
PINENTRY_LAUNCHED 94492 tty 1.2.1 /dev/pts/5 tmux-256color - ? 1001/1001 
0
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_8 <- END
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> SETKEYINFO --clear
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> SETDESC Please enter 
the passphrase to export the OpenPGP secret key:%0A%22Alexander 
Leidinger <Alexander at Leidinger.net>%22%0A4096-bit RSA key, ID 
8F31830F9F2772BF,%0Acreated 2016-08-16.%0A
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> SETPROMPT 
Passphrase:
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- OK
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 -> [[Confidential data 
not shown]]
2023-09-08 13:37:53 gpg-agent[94491] DBG: chan_9 <- [[Confidential data 
not shown]]
2023-09-08 13:37:54 gpg-agent[94491] DBG: error calling pinentry: 
Operation cancelled <Pinentry>
2023-09-08 13:37:54 gpg-agent[94491] DBG: chan_9 -> BYE
2023-09-08 13:37:54 gpg-agent[94491] failed to unprotect the secret key: 
Operation cancelled
2023-09-08 13:37:54 gpg-agent[94491] command 'EXPORT_KEY' failed: 
Operation cancelled <Pinentry>
2023-09-08 13:37:54 gpg-agent[94491] DBG: chan_8 -> ERR 83886179 
Operation cancelled <Pinentry>
2023-09-08 13:37:54 gpg-agent[94491] DBG: chan_8 <- [eof]
---snip---

No idea where the "ERR 83886254 Unknown option <Pinentry>" is coming 
from, I don't have "Pinentry" in any options file.

> Reminder: In case of any problems, please try invoking gpg with
> --verbose (or -v).  You will see more diagnostics.

The verbose output (which doesn't reveal anything new):
---snip---
gpg: enabled compatibility flags:
gpg: writing to 'netchild_sec.pgp'
gpg: key 89DE8BFC8A2A81F8C9BD2F7940C7373A4DE34E7C: asking agent for the 
secret parts
gpg: Note: signature key 0439FFA68121245E expired 2021-06-16 14:41:02
gpg: Note: signature key AAF1421A85208084 expired 2021-06-16 14:40:46
gpg: pinentry launched (15243 tty 1.2.1 /dev/pts/5 tmux-256color - ? 
1001/1001 0)
gpg: key 89DE8BFC8A2A81F8C9BD2F7940C7373A4DE34E7C: error receiving key 
from agent: Operation cancelled - skipped
gpg: WARNING: nothing exported
---snip---

Bye,
Alexander.

-- 
http://www.Leidinger.net Alexander at Leidinger.net: PGP 0x8F31830F9F2772BF
http://www.FreeBSD.org    netchild at FreeBSD.org  : PGP 0x8F31830F9F2772BF
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: OpenPGP digital signature
URL: <https://lists.gnupg.org/pipermail/gnupg-users/attachments/20230908/7bc10f97/attachment-0001.sig>