I’ll work on getting gpg-agent log output next. For now, this is what shows up between the two versions for --list-packets -v(with the data redacted, but it’s the same between the two):
PS C:\temp\gpg> C:\gpg\gpg-2.2.42\bin\gpg.exe --list-packets -v .\not-working.pdf.pgp
gpg: enabled compatibility flags:
gpg: public key is 681D100FD32A7C6B
gpg: using subkey 681D100FD32A7C6B instead of primary key 0521D2004C296FA5
gpg: WARNING: cipher algorithm AES not found in recipient preferences
gpg: using subkey 681D100FD32A7C6B instead of primary key 0521D2004C296FA5
gpg: encrypted with 1024-bit RSA key, ID 681D100FD32A7C6B, created 2016-10-24
"My Name <myname@company.com>"
gpg: AES encrypted data
# off=0 ctb=c1 tag=1 hlen=2 plen=140 new-ctb
:pubkey enc packet: version 3, algo 1, keyid 681D100FD32A7C6B
data: 22E2..2A99
# off=142 ctb=d2 tag=18 hlen=2 plen=0 partial new-ctb
:encrypted data packet:
length: unknown
mdc_method: 2
# off=163 ctb=a3 tag=8 hlen=1 plen=0 indeterminate
:compressed packet: algo=2
# off=165 ctb=cb tag=11 hlen=2 plen=0 partial new-ctb
:literal data packet:
mode b (62), created 1707507901, name="",
raw data: unknown length
And gpg 2.3.0:
PS C:\temp\gpg> C:\gpg\gpg-2.3.0\bin\gpg.exe --list-packets -v .\not-working.pdf.pgp
gpg: Note: RFC4880bis features are enabled.
gpg: public key is 681D100FD32A7C6B
gpg: using subkey 681D100FD32A7C6B instead of primary key 0521D2004C296FA5
gpg: encrypted with rsa1024 key, ID 681D100FD32A7C6B, created 2016-10-24
"My Name <myname@company.com>"
gpg: public key decryption failed: No secret key
gpg: decryption failed: No secret key
# off=0 ctb=c1 tag=1 hlen=2 plen=140 new-ctb
:pubkey enc packet: version 3, algo 1, keyid 681D100FD32A7C6B
data: 22E2..2A99
# off=142 ctb=d2 tag=18 hlen=2 plen=0 partial new-ctb
:encrypted data packet:
length: unknown
mdc_method: 2
As for the software the client uses, I will try to find that out, but I’m not in direct communication with them.
EDIT: Ok, with a log file enabled(and verbose turned on in gpg-agent.conf), I get the following outputs for 2.2.42 and 2.3.0(with gpg-agent being killed between attempts):
2024-02-15 15:20:24 gpg-agent[1092] listening on socket 'C:\Users\chris\AppData\Local\gnupg\S.gpg-agent'
2024-02-15 15:20:24 gpg-agent[1092] listening on socket 'C:\Users\chris\AppData\Local\gnupg\S.gpg-agent.extra'
2024-02-15 15:20:24 gpg-agent[1092] listening on socket 'C:\Users\chris\AppData\Local\gnupg\S.gpg-agent.browser'
2024-02-15 15:20:24 gpg-agent[1092] listening on socket 'C:\Users\chris\AppData\Local\gnupg\S.gpg-agent.ssh'
2024-02-15 15:20:24 gpg-agent[1092] gpg-agent (GnuPG) 2.2.42 started
2024-02-15 15:20:25 gpg-agent[1092] handler 0x2 for fd 132 started
2024-02-15 15:20:26 gpg-agent[1092] handler 0x2 for fd 132 terminated
2024-02-15 15:21:28 gpg-agent[1092] handler 0x3 for fd 616 started
2024-02-15 15:21:28 gpg-agent[1092] socket is still served by this server
2024-02-15 15:21:28 gpg-agent[1092] handler 0x3 for fd 616 terminated
2024-02-15 15:24:47 gpg-agent[28096] listening on socket 'C:\\Users\\chris\\AppData\\Roaming\\gnupg\\S.gpg-agent'
2024-02-15 15:24:47 gpg-agent[28096] listening on socket 'C:\\Users\\chris\\AppData\\Roaming\\gnupg\\S.gpg-agent.extra'
2024-02-15 15:24:47 gpg-agent[28096] listening on socket 'C:\\Users\\chris\\AppData\\Roaming\\gnupg\\S.gpg-agent.browser'
2024-02-15 15:24:47 gpg-agent[28096] listening on socket 'C:\\Users\\chris\\AppData\\Roaming\\gnupg\\S.gpg-agent.ssh'
2024-02-15 15:24:47 gpg-agent[28096] gpg-agent (GnuPG) 2.3.0 started
2024-02-15 15:24:49 gpg-agent[28096] handler 0x2 for fd 132 started
2024-02-15 15:24:49 gpg-agent[28096] Assuan get_peercred failed: General IPC error
2024-02-15 15:24:49 gpg-agent[28096] handler 0x2 for fd 132 terminated
The one thing I do note is the line “Assuan get_peercred failed: General IPC error”, but I’m not sure what that means.
Is there anything else I should try to log?
EDIT2: I’ve turned on debug-all, and have some results with the channel communications with gpg-agent, but I’m not sure if it points to anything.
These have all been redacted to remove sensitive info(I believe), but still show what I’m seeing.
The first is the not working file in 2.3.0:
2024-02-15 15:35:28 gpg-agent[10372] gpg-agent (GnuPG) 2.3.0 started
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 -> OK Pleased to meet you
2024-02-15 15:35:30 gpg-agent[10372] Assuan get_peercred failed: General IPC error
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 <- RESET
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 -> OK
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 <- GETINFO version
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 -> D 2.3.0
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 -> OK
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 <- OPTION allow-pinentry-notify
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 -> OK
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 <- OPTION agent-awareness=2.1.0
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 -> OK
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 <- SCD SERIALNO
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 -> ERR 67108924 Not supported <GPG Agent>
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 <- HAVEKEY ..024D ..8E77
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 -> OK
2024-02-15 15:35:30 gpg-agent[10372] DBG: chan_0x00000084 <- [eof]
I’m a little confused why the gpg client seems to just end the connection there?
Here’s a working file in gpg 2.3.0:
2024-02-15 15:55:19 gpg-agent[20876] gpg-agent (GnuPG) 2.3.0 started
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 -> OK Pleased to meet you
2024-02-15 15:55:21 gpg-agent[20876] Assuan get_peercred failed: General IPC error
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 <- RESET
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 -> OK
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 <- GETINFO version
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 -> D 2.3.0
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 -> OK
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 <- OPTION allow-pinentry-notify
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 -> OK
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 <- OPTION agent-awareness=2.1.0
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 -> OK
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 <- SCD SERIALNO
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 -> ERR 67108924 Not supported <GPG Agent>
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 <- HAVEKEY ..024D ..8E77
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 -> OK
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 <- RESET
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 -> OK
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 <- SETKEY ..8E77
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 -> OK
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 <- SETKEYDESC Please+enter+the+passphrase+to+unlock+the+OpenPGP+secret+key:%0A%22My+Name+<MyName@company.com>%22%0A1024-bit+RSA+key,+ID+681D100FD32A7C6B,%0Acreated+2016-10-24+(main+key+ID+0521D2004C296FA5).%0A
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 -> OK
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 <- PKDECRYPT
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 -> S INQUIRE_MAXLEN 4096
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 -> INQUIRE CIPHERTEXT
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_00000088 <- [ 44 20 28 37 3a 65 6e 63 2d 76 61 6c 28 33 3a 72 ...(147 byte(s) skipped) ]
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 <- END
2024-02-15 15:55:21 gpg-agent[20876] DBG: keygrip: ..8E77
2024-02-15 15:55:21 gpg-agent[20876] DBG: cipher: 2837 .. [MANUALLY DELETED]
2024-02-15 15:55:21 gpg-agent[20876] DBG: rsa_decrypt data: [MANUALLY DELETED]
2024-02-15 15:55:21 gpg-agent[20876] DBG: rsa_decrypt => Success
2024-02-15 15:55:21 gpg-agent[20876] DBG: plain: [data="MANUALLY DELETED"]
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_00000088 -> [ 44 20 28 35 3a 76 61 6c 75 65 31 32 37 3a 02 42 ...(127 byte(s) skipped) ]
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 -> OK
2024-02-15 15:55:21 gpg-agent[20876] DBG: chan_0x00000088 <- [eof]
And finally, the not working file in gpg 2.2.42:
2024-02-15 15:36:30 gpg-agent[23268] gpg-agent (GnuPG) 2.2.42 started
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> OK Pleased to meet you
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 <- RESET
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> OK
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 <- GETINFO version
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> D 2.2.42
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> OK
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 <- OPTION allow-pinentry-notify
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> OK
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 <- OPTION agent-awareness=2.1.0
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> OK
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 <- KEYINFO ..8E77
2024-02-15 15:36:32 gpg-agent[23268] DBG: agent_get_cache '..8E77'.0 (mode 2) ...
2024-02-15 15:36:32 gpg-agent[23268] DBG: ... miss
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> S KEYINFO ..8E77 D - - - C - - -
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> OK
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 <- HAVEKEY ..024D ..8E77
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> OK
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 <- KEYINFO ..8E77
2024-02-15 15:36:32 gpg-agent[23268] DBG: agent_get_cache '..8E77'.0 (mode 2) ...
2024-02-15 15:36:32 gpg-agent[23268] DBG: ... miss
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> S KEYINFO ..8E77 D - - - C - - -
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> OK
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 <- RESET
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> OK
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 <- SETKEY ..8E77
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> OK
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 <- SETKEYDESC Please+enter+the+passphrase+to+unlock+the+OpenPGP+secret+key:%0A%22My+Name+<myname@company.com>%22%0A1024-bit+RSA+key,+ID+681D100FD32A7C6B,%0Acreated+2016-10-24+(main+key+ID+0521D2004C296FA5).%0A
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> OK
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 <- PKDECRYPT
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> S INQUIRE_MAXLEN 4096
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> INQUIRE CIPHERTEXT
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_00000088 <- [ 44 20 28 37 3a 65 6e 63 2d 76 61 6c 28 33 3a 72 ...(143 byte(s) skipped) ]
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 <- END
2024-02-15 15:36:32 gpg-agent[23268] DBG: keygrip: .. .. .. .. .. .. .. .. .. .. .. .. .. .. .. .. .. .. 8E 77
2024-02-15 15:36:32 gpg-agent[23268] DBG: cipher: 28 37 .. [MANUALLY DELETED]
2024-02-15 15:36:32 gpg-agent[23268] DBG: rsa_decrypt data: [MANUALLY DELETED]
2024-02-15 15:36:32 gpg-agent[23268] DBG: rsa_decrypt => Success
2024-02-15 15:36:32 gpg-agent[23268] DBG: plain: [data="MANUALLY DELETED"]
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_00000088 -> [ 44 20 28 35 3a 76 61 6c 75 65 31 32 37 3a 02 94 ...(129 byte(s) skipped) ]
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 -> OK
2024-02-15 15:36:32 gpg-agent[23268] DBG: chan_0x00000088 <- [eof]