Autocrypt importing after delete from gpg

[Greg Hill]

Having an issue with autocrypt keys being imported, and hoping you might be able to help.
Scenario:
Email sent with autocrypt header. I can see the autocrypt header is found and imported by looking in the sqlLite database
Reply to email: Key seems to be imported into the Enigmail KeyManager (and gpg), and can send encrypted reply

.... great so far ....

Key gets deleted from gpg (for testing autocrypt, or other reasons)

Reload email and try to reply: Key is not imported into gpg again. Shows the "Recipients not valid" dialog with the correct Key ID displayed as the Recipient, followed by No Valid Key. E.G.
0x7524....1C: No valid key

Try deleting the key from the autocrypt table in SqlLite and re-opening email. Key gets repopulated in the autocrypt table, but still won't be imported into GPG again.

Is there some cache that prevents a deleted key from being re-imported from autocrypt?

Thanks. I have attached log below when trying this with the autocrypt bot. Again, worked before the key was deleted from gpg

---

2019-04-15 10:54:46.438 [DEBUG] enigmailMsgComposeOverlay.js: Enigmail.msg.processRules(): toAddrStr="bot@autocrypt.org" bccAddrStr="" forceRecipientSettings=false
2019-04-15 10:54:46.438 [DEBUG] rules.jsm: mapAddrsToKeys(): emailAddrsStr="bot@autocrypt.org" startDialogForMissingKeys=false
2019-04-15 10:54:46.439 [DEBUG] rules.jsm: getRulesData()
2019-04-15 10:54:46.439 [DEBUG] rules.jsm: mapAddrsToKeys(): rules successfully loaded; now process them
2019-04-15 10:54:46.440 [DEBUG] rules.jsm: mapRuleToKeys(): for 'bot@autocrypt.org' ('bot@autocrypt.org') found matching rule element '{autocrypt://bot@autocrypt.org}'
2019-04-15 10:54:46.441 [DEBUG] found keys:
2019-04-15 10:54:46.441 [DEBUG] bot@autocrypt.org: 0xBC956F0DEF583F7E9B96ECC28621EFB8185D8053
2019-04-15 10:54:46.441 [DEBUG] addresses without keys:
2019-04-15 10:54:46.441 [DEBUG] old returned value:
2019-04-15 10:54:46.441 [DEBUG] 0xBC956F0DEF583F7E9B96ECC28621EFB8185D8053
2019-04-15 10:54:46.441 [DEBUG] enigmailMsgComposeOverlay.js: Enigmail.msg.processRules(): after mapAddrsToKeys() toAddrStr="0xBC956F0DEF583F7E9B96ECC28621EFB8185D8053"
2019-04-15 10:54:46.441 [DEBUG] enigmailMsgComposeOverlay.js: Enigmail.msg.processFinalState()
2019-04-15 10:54:46.441 [DEBUG] enigmailMsgComposeOverlay.js: encrypt=false encryptByRules=0 encFinally=11
2019-04-15 10:54:46.441 [DEBUG] encReason=manually forced
2019-04-15 10:54:46.441 [DEBUG] enigmailMsgComposeOverlay.js: signed=false signByRules=0 signFinally=0
2019-04-15 10:54:46.441 [DEBUG] signReason=forced by per-recipient rules
2019-04-15 10:54:46.441 [DEBUG] enigmailMsgComposeOverlay.js: pgpmimeByRules=2 pgpmimeFinally=1
2019-04-15 10:54:46.441 [DEBUG] rules.jsm: mapAddrsToKeys(): emailAddrsStr="" startDialogForMissingKeys=false
2019-04-15 10:54:46.442 [DEBUG] rules.jsm: getRulesData()
2019-04-15 10:54:46.442 [DEBUG] rules.jsm: mapAddrsToKeys(): rules successfully loaded; now process them
2019-04-15 10:54:46.442 [DEBUG] found keys:
2019-04-15 10:54:46.442 [DEBUG] addresses without keys:
2019-04-15 10:54:46.442 [DEBUG] old returned value:
2019-04-15 10:54:46.442 [DEBUG]
2019-04-15 10:54:46.442 [DEBUG] <=== processRules()
2019-04-15 10:54:46.442 [DEBUG] =====> encryptTestMessage()
2019-04-15 10:54:46.442 [DEBUG] =====> validKeysForAllRecipients()
2019-04-15 10:54:46.442 [DEBUG] enigmailMsgComposeHelper.js: validKeysForAllRecipients(): emailsOrKeys='0xBC956F0DEF583F7E9B96ECC28621EFB8185D8053'
2019-04-15 10:54:46.442 [DEBUG] enigmailMsgComposeHelper.js: doValidKeysForAllRecipients(): emailsOrKeys='0xBC956F0DEF583F7E9B96ECC28621EFB8185D8053'
2019-04-15 10:54:46.442 [DEBUG] enigmailMsgComposeHelper.js: doValidKeysForAllRecipients(): find keys with minTrustLevel="?"
2019-04-15 10:54:46.442 execution.jsm: EnigmailExecution.execCmd: subprocess = 'C:\Program Files (x86)\GnuPG\bin\gpg.exe'
2019-04-15 10:54:46.442 [CONSOLE] enigmail> "C:\Program Files (x86)\GnuPG\bin\gpg.exe" --charset utf-8 --display-charset utf-8 --no-auto-check-trustdb --batch --no-tty --no-verbose --status-fd 2 --fixed-list-mode --with-colons --list-config
2019-04-15 10:54:46.515 [DEBUG] enigmail> DONE
2019-04-15 10:54:46.515 [DEBUG] execution.jsm: EnigmailExecution.execCmd: exitCode = 0
2019-04-15 10:54:46.515 [DEBUG] execution.jsm: EnigmailExecution.execCmd: errOutput =
2019-04-15 10:54:46.515 [DEBUG] errorHandling.jsm: parseErrorOutputWith: status message:

2019-04-15 10:54:46.516 [DEBUG] system.jsm: determineSystemCharset
2019-04-15 10:54:46.516 [DEBUG] system.jsm: determineSystemCharset: charset='437'
2019-04-15 10:54:46.516 [DEBUG] errorHandling.jsm: parseErrorOutputWith: statusFlags = 00000000
2019-04-15 10:54:46.516 [DEBUG] errorHandling.jsm: parseErrorOutputWith: return with c.errorMsg =
2019-04-15 10:54:46.516 [DEBUG] execution.jsm: EnigmailExecution.fixExitCode: agentType: gpg exitCode: 0 statusFlags undefined
2019-04-15 10:54:46.516 [CONSOLE]
2019-04-15 10:54:46.516 [DEBUG] keyRing.jsm: getKeyById: 0xBC956F0DEF583F7E9B96ECC28621EFB8185D8053
2019-04-15 10:54:46.517 [DEBUG] keyRing.jsm: doValidKeysForAllRecipients(): return null (no single valid key found for="0xBC956F0DEF583F7E9B96ECC28621EFB8185D8053" with minTrustLevel="?")
2019-04-15 10:54:46.517 [DEBUG] enigmailMsgComposeHelper.js: doValidKeysForAllRecipients(): return null (key missing)
2019-04-15 10:54:46.517 [DEBUG] enigmailMsgComposeHelper.js: validKeysForAllRecipients(): return 'null'
2019-04-15 10:54:46.517 [DEBUG] <=== validKeysForAllRecipients()
2019-04-15 10:54:46.517 [DEBUG] enigmailMsgComposeOverlay.js: Enigmail.msg.encryptTestMessage(): call encryptMessage() for fromAddr="0x2F70CB7DF2D5518E7A658F64C097E46D12236148" toAddrStr="0xBC956F0DEF583F7E9B96ECC28621EFB8185D8053" bccAddrStr=""
2019-04-15 10:54:46.517 [DEBUG] enigmail.js: Enigmail.encryptMessage: 12 bytes from 0x2F70CB7DF2D5518E7A658F64C097E46D12236148 to 0xBC956F0DEF583F7E9B96ECC28621EFB8185D8053 (354)
2019-04-15 10:54:46.517 [DEBUG] encryption.jsm: encryptMessageStart: uiFlags=16, from 0x2F70CB7DF2D5518E7A658F64C097E46D12236148 to 0xBC956F0DEF583F7E9B96ECC28621EFB8185D8053, hashAlgorithm=null (00000162)
2019-04-15 10:54:46.517 [DEBUG] encryption.jsm: determineOwnKeyUsability: sendFlags=354, sender=0x2F70CB7DF2D5518E7A658F64C097E46D12236148
2019-04-15 10:54:46.517 [DEBUG] keyRing.jsm: getKeyById: 0x2F70CB7DF2D5518E7A658F64C097E46D12236148
2019-04-15 10:54:46.517 [DEBUG] encryption.jsm: getEncryptCommand: hashAlgorithm=null
2019-04-15 10:54:46.519 execution.jsm: execStart: command = "C:\Program Files (x86)\GnuPG\bin\gpg.exe" --charset utf-8 --display-charset utf-8 --no-auto-check-trustdb --batch --no-tty --no-verbose --status-fd 2 --log-file C:\Users\greg\AppData\Local\Temp\gpgOutput.q4FPHu -a -t --encrypt --trust-model always --encrypt-to 0x2F70CB7DF2D5518E7A658F64C097E46D12236148 -r 0xBC956F0DEF583F7E9B96ECC28621EFB8185D8053 -u 0x2F70CB7DF2D5518E7A658F64C097E46D12236148, needPassphrase=0, domWindow=[object ChromeWindow], listener=[object Object]
2019-04-15 10:54:46.519 [CONSOLE] enigmail> "C:\Program Files (x86)\GnuPG\bin\gpg.exe" --charset utf-8 --display-charset utf-8 --no-auto-check-trustdb --batch --no-tty --no-verbose --status-fd 2 --log-file C:\Users\greg\AppData\Local\Temp\gpgOutput.q4FPHu -a -t --encrypt --trust-model always --encrypt-to 0x2F70CB7DF2D5518E7A658F64C097E46D12236148 -r 0xBC956F0DEF583F7E9B96ECC28621EFB8185D8053 -u 0x2F70CB7DF2D5518E7A658F64C097E46D12236148
2019-04-15 10:54:46.520 [DEBUG] enigmail> DONE
2019-04-15 10:54:46.605 [DEBUG] errorHandling.jsm: Process terminated. Human-readable output from gpg:

---

[Patrick Brunschwig]

For performance reasons, Enigmail caches the keys in memory. If you delete a key in gpg, then Enigmail won't notice this until it reloads the cache (which it would not do quite rarely). Did you reload the key cache in Enigmail after deleting the key in gpg?

The function is available from the Enigmail Key Manager, menu File

[Greg Hill]

Alas, refreshing isn't helping.
Issue seems to be that it pulls the keyId from the autocrypt table, then searches based on the keyId...and fails there for some reason.
This has been reproduced both by myself and the QA team for my software.

Thanks
Greg

[Patrick Brunschwig]

Ah, sorry, I didn't consider everything.

First of all, you have to consider that the Autocrypt implementation in Enigmail 2.0 is not (claimed to be) complete. There are several parts of the Autocrypt specificaton that are not handled in Enigmail at all, such as updates to keys and key gossip.

Autocrypt is supposed to be automatic and you're not expected to do key managment for Autocrypt keys. This includes deleting keys. I have implented it that way in Enigmail, but obviously I can't stop you from doing key management in GnuPG. However, Enigmail is not prepared for this scenario.

When an Autocrypt key is imported by Enigmail, then Enigmail creates a hidden per-recipient rule for that key. Now deleting the key will obviously not delete the per-recipient rule, and hence will apply the per-recpient rule - just to find out that the specified key ID is not available.

I'm assuming you try to delete the key in order to test your Autocrypt implementation, as I can't see any other reason why you'd want to delete a key, just to have it re-imported. That said, after you deleted a key in gpg, you also have to delete the corresponding per-recipient rule. You'll need to do that manually, by editing pgprules.xml in the Thunderbird profile, and restart Thunderbird afterwards.

[Greg Hill]

Thanks! That was it.
Appreciate the help.