astroid icon indicating copy to clipboard operation
astroid copied to clipboard

GPG2 decryption fails

Open xxxserxxx opened this issue 6 years ago • 16 comments

Astroid: v0.15-14-g964c1c70

Astroid is reporting an error decrypting GPG-encrypted messages that decrypt successfully from the command line. Here's the error:

[18:18:55] [0x00007ff31f625c40] [M] [info] msg: loading mid: [email protected]
[18:18:55] [0x00007ff31f625c40] [M] [info] msg: filename: /home/ser/.mail/ser1/INBOX/cur/1586987577_0.1203341.glamdring,U=67125,FMD5=7e33429f656f1e6e9d79b29c3f82c57e:2,S
[18:18:55] [0x00007ff31f625c40] [M] [debug] chunk (0): content-type: multipart/encrypted
[18:18:55] [0x00007ff31f625c40] [M] [debug] chunk: multi part
[18:18:55] [0x00007ff31f625c40] [M] [debug] crypto: gpg: /usr/bin/gpg2
[18:18:55] [0x00007ff31f625c40] [M] [warning] chunk: is encrypted.
[18:18:55] [0x00007ff31f625c40] [M] [debug] crypto: decrypting and verifiying..
[18:18:55] [0x00007ff31f625c40] [M] [error] crypto: failed to decrypt message: Cannot decrypt multipart/encrypted part: failed to parse decrypted content.
[18:18:55] [0x00007ff31f625c40] [M] [debug] chunk: multi part end

Here's the relevant GPG configuration:

➜  ~ jq '.crypto' .config/astroid/config
{
  "gpg": {
    "path": "/usr/bin/gpg2",
    "always_trust": "true",
    "enabled": "true"
  }
}

And here's a (trimmed) copy of a successful decryption of the message, which demonstrates that

  1. The same encryption key is being used as referenced in the config
  2. The same gpg2 binary is being used for the operation
  3. The same message file is being decrypted that is referenced in the log
  4. The decryption is successful
➜  ~ /usr/bin/gpg2 -d /home/ser/.mail/ser1/INBOX/cur/1586987577_0.1203341.glamdring,U=67125,FMD5=7e33429f656f1e6e9d79b29c3f82c57e:2,S
gpg: encrypted with 2048-bit RSA key, ID 5D182635BB0B5256, created 2020-01-31
      "Sean E. Russell (@ser:matrix.ser1.net) <[email protected]>"
From nobody Wed Apr 15 21:50:41 2020
Content-Type: multipart/signed; micalg="pgp-sha512"; protocol="application/pgp-signature"; boundary="===============0596304912901756560=="
MIME-Version: 1.0

--===============0596304912901756560==
Content-Type: text/plain; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit

This is a test email sent from sourcehut to confirm that PGP is working as you
expect. This email is signed with this key:

447B 69E4 B34B E90B C829 A0E9 6597 04D1 A38A 93AE

and is encrypted with this key:

12B7 DD00 82BD 2B37 C5BC  A825 2AC7 CCA6 8765 1D71

You may control your PGP settings here:

https://meta.sr.ht/privacy

--
Drew DeVault
sourcehut

--===============0596304912901756560==
Content-Type: application/pgp-signature; name="signature.asc"
Content-Description: OpenPGP digital signature

-----BEGIN PGP SIGNATURE-----

wsBcBAABCgAGBQJel4GxAAoJEGWXBNGjipOuw/MH/i5TYyqFjRXjSh+Qv7Gd8zXd
...
=/eMJ
-----END PGP SIGNATURE-----

--===============0596304912901756560==--

The only thing I can think of is that Astroid is trying to decrypt the wrong attachment. The log level is at debug and there's not a lot to go on in the error message.

xxxserxxx avatar Apr 16 '20 23:04 xxxserxxx

There might be some hints in https://github.com/astroidmail/astroid/issues/645 on how to test and also increase debug from gmime and gpg.

gauteh avatar Apr 17 '20 09:04 gauteh

@gauteh Thanks. It's like that meme where you have a problem & go looking for an answer, and find a post by yourself a couple of years ago asking the same question and getting an answer. I'd forgotten about the GPG debugging env var.

I didn't find a ticket with similar behavior, but if it turns out to be the same issue I'll close this. Thanks again.

xxxserxxx avatar Apr 17 '20 16:04 xxxserxxx

Okaaaay... so, I don't know what I'm seeing. The GPG logs clearly show that GPG is decrypting the message and giving it back to Astroid -- I can read the decrypted message in the logs. I don't know why Astroid thinks decryption failed, because I don't see anything that looks like "failure" to me in the log -- in fact, there's a "status=success" message. It's in the non-gpgme logs, and in the UI, that Astroid says decryption failed.

I'm attaching the log (filtered with egrep 'gpg|crypto'), but because it's rather large, the most interesting part for me is this:

GPGME 20200417T114428 171489  gpgme_op_decrypt_result: check: ctx=0x000055b08f1412a0 
      result: recipient: keyid=5D182635BB0B5256, pubkey_algo=1, status=Success
GPGME 20200417T114428 171489  gpgme_op_decrypt_result: leave: result=0x000055b08f118470
GPGME 20200417T114428 171489  gpgme_release: call: ctx=0x000055b08f1412a0
GPGME 20200417T114428 171489  gpgme_data_release: call: dh=0x0000000000000000
GPGME 20200417T114428 171489  gpgme_data_release: call: dh=0x000055b08f1173e0
[11:44:28] [0x00007f2a401c2c40] [M] [error] crypto: failed to decrypt message: Cannot 
      decrypt multipart/encrypted part: failed to parse decrypted content.
[11:44:32] [0x00007f2a401c2c40] [M] [debug] crypto: deconstruct.

(Emphasis and formatting was added for readability)

astroid_debug.txt

xxxserxxx avatar Apr 17 '20 16:04 xxxserxxx

Before we have had issues if any of the keys are expired or not trusted. Or if there are keys with conflicting IDs. I think that parse-failed message is in gmime or gpgme. Can't remember it being from astroid.

fre. 17. apr. 2020, 18:51 skrev xxxserxxx [email protected]:

Okaaaay... so, I don't know what I'm seeing. The GPG logs clearly show that GPG is decrypting the message and giving it back to Astroid -- I can read the decrypted message in the logs. I don't know why Astroid thinks decryption failed, because I don't see anything that looks like "failure" to me in the log -- in fact, there's a "status=success" message. It's in the non-gpgme logs, and in the UI, that Astroid says decryption failed.

I'm attaching the log (filtered with egrep 'gpg|crypto'), but because it's rather large, the most interesting part for me is this:

GPGME 20200417T114428 171489 gpgme_op_decrypt_result: check: ctx=0x000055b08f1412a0 result: recipient: keyid=5D182635BB0B5256, pubkey_algo=1, status=Success GPGME 20200417T114428 171489 gpgme_op_decrypt_result: leave: result=0x000055b08f118470 GPGME 20200417T114428 171489 gpgme_release: call: ctx=0x000055b08f1412a0 GPGME 20200417T114428 171489 gpgme_data_release: call: dh=0x0000000000000000 GPGME 20200417T114428 171489 gpgme_data_release: call: dh=0x000055b08f1173e0 [11:44:28] [0x00007f2a401c2c40] [M] [error] crypto: failed to decrypt message: Cannot decrypt multipart/encrypted part: failed to parse decrypted content. [11:44:32] [0x00007f2a401c2c40] [M] [debug] crypto: deconstruct.

(Emphasis and formatting was added for readability)

astroid_debug.txt https://github.com/astroidmail/astroid/files/4494196/astroid_debug.txt

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/astroidmail/astroid/issues/679#issuecomment-615352929, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAAN36YWXALUSBBWDGI75HTRNCCHPANCNFSM4MKJS73Q .

gauteh avatar Apr 17 '20 16:04 gauteh

I experienced this before, and based on one of the other tickets cleaned out my keychain a while ago. Until then, I was having trouble with signing and encrypting, but that's been working for a couple of months and still works. It's just decryption that's broken now. I can sign emails to myself. Furthermore, I can encrypt and sign messages to myself and they're decrypting. It is just the message from sr.ht (Sourcehut) that's failing.

On further inspection, when I sign and encrypt to myself it's signing with one key, and encrypting to a different key. Both are valid and active; one is rsa1024 and the other is rsa2048. The message that's failing is encrypted with the more recent rsa2048.

Incidentally, GPG's groups is working for GPG, but Astroid isn't picking it up. If I put a bogus value in, Astroid complains that it can't find the key, but if I put in the rsa2048 key value in, Astroid ignores it and uses the rsa1024 key for encryption. E.g.,

➜  ~ grep group .gnupg/gpg.conf
group [email protected] = 12B7DD0082BD2B37C5BCA8252AC7CCA687651D71

When used on the command line gpg -e --recipient [email protected], GnuPG chooses the correct (rsa2048) key. However, Astroid continues to choose the wrong (rsa1024) encryption key.

Maybe it's related? Maybe when presented with multiple keys, Astroid always chooses the wrong (e.g., the first) decryption key? I'm guessing here, but it's possible the two issues are related.

xxxserxxx avatar Apr 18 '20 16:04 xxxserxxx

cc @bernhardreiter, perhaps interesting for your debugging work (if it's still ongoing)

mxmehl avatar Apr 19 '20 12:04 mxmehl

@xxxserxxx from my experience: If decryption of the raw contents with gpg works, as you have indicated, then it is not primarily a pubkey selection problem anymore. So the problems selection a good pubkey for encryption is most likely to be unrelated.

@mxmehl no, not related to the pubkey selection problems.

bernhardreiter avatar Apr 21 '20 10:04 bernhardreiter

I think maybe the next step is to create a minimal gmime-program to try and parse / decrypt the message: https://github.com/jstedfast/gmime/blob/master/tests/test-pgpmime.c or crypto.cc in astroid. perhaps it is a problem not with decryption, but the mime-structure of the message?

gauteh avatar Apr 21 '20 11:04 gauteh

It's probably the mime structure. It's been -- literally -- decades since I touched C. I'll have to see if I can figure enough out for a test.

You don't know of a test program using the gmime kit that I can pipe a message in from the command line?

xxxserxxx avatar Apr 21 '20 14:04 xxxserxxx

You could try saving it to the maildir and open with another notmuch. Or use the simple python email parser examples. There are some one-liners there. They don't use gmime though.

tir. 21. apr. 2020, 16:58 skrev xxxserxxx [email protected]:

It's probably the mime structure. It's been -- literally -- decades since I touched C. I'll have to see if I can figure enough out for a test.

You don't know of a test program using the gmime kit that I can pipe a message in from the command line?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/astroidmail/astroid/issues/679#issuecomment-617233693, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAAN367PEX6Q6S2KW5W3D7TRNWYBPANCNFSM4MKJS73Q .

gauteh avatar Apr 21 '20 15:04 gauteh

What am I testing? If I save the raw message, I can easily decrypt it with GPG directly, but this is obviously doing nothing with the mime. I ran the message through munpack (from the mpack project), and it decoded the email into two parts without complaint, so the mime encoding looks fine; I then ran GPG on the message part, and it decrypted.

When you say "another notmuch," what do you mean? When I try to notmuch show the message, it also gives me an error, Failed to decrypt part: no error explanation given. When I use the mime debugging tool from notmuch, it does not produce an error:

➜  email cat testemail.eml| ./email-print-mime-structure --no-use-gpg-agent
└┬╴multipart/encrypted 3260 bytes
 ├─╴application/pgp-encrypted 10 bytes
 └─╴application/octet-stream [message.asc] 1662 bytes
➜  email cat testemail.eml| ./email-print-mime-structure --use-gpg-agent
└┬╴multipart/encrypted 3260 bytes
 ├─╴application/pgp-encrypted 10 bytes
 └─╴application/octet-stream [message.asc] 1662 bytes
  ↧ (decrypts to)
  └┬╴multipart/signed 1296 bytes
   ├─╴text/plain 356 bytes
   └─╴application/pgp-signature [signature.asc] 455 bytes

and in fact decrypts the message fine. Is it possible to get Astroid to use the gpg-agent?

The email from sourcehut is not sensitive, and I'd upload it except you can't do anything with it since it's encypted with my key. However, I do see something interesting: there are two parts to the message, one that's not encrypted, and a second that is. I wonder if the notmuch (and Astroid) are trying to decrypt the first part, and since it's not encrypted, GPG generates an error (this is trimmed):

Content-Type: multipart/encrypted; protocol="application/pgp-encrypted"; boundary="===============8986875417254470581=="
MIME-Version: 1.0
Subject: Test email
From: sourcehut <[email protected]>
To: [email protected]
Date: Wed, 15 Apr 2020 21:50:41 -0000
Message-ID: <[email protected]>

--===============8986875417254470581==
Content-Type: application/pgp-encrypted

Version: 1
--===============8986875417254470581==
Content-Type: application/octet-stream; name="message.asc"
Content-Description: OpenPGP encrypted message

-----BEGIN PGP MESSAGE-----

xxxserxxx avatar Apr 22 '20 00:04 xxxserxxx

That can't be the issue; the email conforms to RFC 3156; specifically, section 4 says:

The multipart/encrypted MIME body MUST consist of exactly two body parts, the first with content type "application/pgp-encrypted". This body contains the control information. A message complying with this standard MUST contain a "Version: 1" field in this body. Since the OpenPGP packet format contains all other information necessary for decrypting, no other information is required here.

The second MIME body part MUST contain the actual encrypted data. It MUST be labeled with a content type of "application/octet-stream".

Example message:

 From: Michael Elkins <[email protected]>
 To: Michael Elkins <[email protected]>
 Mime-Version: 1.0
 Content-Type: multipart/encrypted; boundary=foo;
    protocol="application/pgp-encrypted"

 --foo
 Content-Type: application/pgp-encrypted

 Version: 1

 --foo
 Content-Type: application/octet-stream

 -----BEGIN PGP MESSAGE-----
 Version: 2.6.2

which matches the format of the sourcehut test message.

xxxserxxx avatar Apr 22 '20 00:04 xxxserxxx

xxxserxxx writes on April 22, 2020 3:36:

What am I testing? If I save the raw message, I can easily decrypt it with GPG directly, but this is obviously doing nothing with the mime. I ran the message through munpack (from the mpack project), and it decoded the email into two parts without complaint, so the mime encoding looks fine; I then ran GPG on the message part, and it decrypted.

When you say "another notmuch," what do you mean? When I try to notmuch show the message, it also gives me an error, Failed to decrypt part: no error explanation given. When I use the mime debugging tool from notmuch, it does not produce an error:

➜  email cat testemail.eml| ./email-print-mime-structure --no-use-gpg-agent
└┬╴multipart/encrypted 3260 bytes
 ├─╴application/pgp-encrypted 10 bytes
 └─╴application/octet-stream [message.asc] 1662 bytes
➜  email cat testemail.eml| ./email-print-mime-structure --use-gpg-agent
└┬╴multipart/encrypted 3260 bytes
 ├─╴application/pgp-encrypted 10 bytes
 └─╴application/octet-stream [message.asc] 1662 bytes
  ↧ (decrypts to)
  └┬╴multipart/signed 1296 bytes
   ├─╴text/plain 356 bytes
   └─╴application/pgp-signature [signature.asc] 455 bytes

and in fact decrypts the message fine. Is it possible to get Astroid to use the gpg-agent?

Astroid is using gpg-agent. If you have gmime < 3 it does the same thing. With newer gmime it is no longer possible to force it, and it should not be necessary (according to: https://developer.gnome.org/gmime/stable/gmime-changes-3-0.html). Are you using gmime2?

gauteh avatar Apr 22 '20 07:04 gauteh

Are you using gmime2?

I don't think so. ldd says my Astroid executable is linked to gmime3:

➜  ~ ldd `which astroid` | grep mime
libgmime-3.0.so.0 => /usr/lib/libgmime-3.0.so.0 (0x00007f9288bcd000)

It is interesting that notmuch also gives an error, but strange that nothing else (notmuch's test script, gmime3, GPG, munpack) reports any problems.

xxxserxxx avatar Apr 22 '20 17:04 xxxserxxx

Yes... weird.. Is notmuch linked to the same gmime?

On Wed, Apr 22, 2020 at 7:53 PM xxxserxxx [email protected] wrote:

Are you using gmime2?

I don't think so. ldd says my Astroid executable is linked to gmime3:

➜ ~ ldd which astroid | grep mime

libgmime-3.0.so.0 => /usr/lib/libgmime-3.0.so.0 (0x00007f9288bcd000)

It is interesting that notmuch also gives an error, but strange that nothing else (notmuch's test script, gmime3, GPG, munpack) reports any problems.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/astroidmail/astroid/issues/679#issuecomment-617933892, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAAN3625OB76SU5WH3PC2W3RN4VJVANCNFSM4MKJS73Q .

gauteh avatar Apr 22 '20 18:04 gauteh

Yes.

➜  gotop git:(master) ✗ ldd `which notmuch` `which astroid` | grep gmime
        libgmime-3.0.so.0 => /usr/lib/libgmime-3.0.so.0 (0x00007ff9767a5000)
        libgmime-3.0.so.0 => /usr/lib/libgmime-3.0.so.0 (0x00007f3693b78000)

Edit

I don't mean to be spartan; I just don't have any ideas about what else I can try here.

xxxserxxx avatar Apr 22 '20 18:04 xxxserxxx