User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:112.0) Gecko/20100101 Firefox/112.0

Steps to reproduce:

I configured "encrypt when possible" in the security settings and then opened a new compose window. In the To field I typed in a real email address (of mine) that I have an encryption key for, and then a nonexistent email address.

Actual results:

After entering each email address, the UI blocked for a significant period while it performed the encryption-possible tests. On MacOS, this presents as the pinwheel of death.

Expected results:

The tests should operate asynchronously (or time out more quickly) so that users can continue to compose their email.

Which technology do you have configured, OpenPGP or S/MIME or both?

OpenPGP using external GnuPG. My internal public keyring has 20 entries, and I also have an aliases file but it only has one entry. The external gpg has 700 keys in its public keyring, and I'm also using quite an old external smartcard with rsa4098 subkeys, but this shouldn't matter for encryption. In any case, the UI should be able to deal gracefully with slow calls. I just tested it again and it took over 2 minutes to return...

Thanks for the description.

I wonder if this is caused by 1762834.
I'll make a test build that puts that querying behind a pref, so you could try to disable it.

Are you using Thunderbird 114 beta ?

Yes, 114 beta, downloaded on the day I opened this ticket.

I wonder if this is caused by 1762834.

Disabling the external gnupg integration makes the problem go away, so this seems likely. Is it polling gnupg for its full keyring every time? This seems excessive...

Hi there.

At the beginning: Sorry, for my English :) but:

I see this behavior on TB 68.12 and Enigmail enabled/configured; my keyring has ~50 keys (openpgp / gnupg) and ~150 keys with S/MIME, when I start to compose new message or replaying to or forwarding something and to, cc or bcc field has more than few address, TB with is lagging - the same as describe in this thread.
I have a suggest: maybe make all checks - at the end - before mail is send – e.g. when user click send - then all recipients should be checked for encryption possibility ?
I think this will do not to slow down when user start to compose, forward or replying a message or add/remove/modify recipient list (cc/to/bcc)

(In reply to Robert from comment #7)

I see this behavior on TB 68.12 and Enigmail enabled/configured; my

Robert, you're using old software, which is no longer maintained, and the Enigmail you are using is very different from the code used by the latest Thunderbird versions.
This discussion here is about the latest stable versions and the new versions under development.

I have a suggest: maybe make all checks - at the end - before mail is send – e.g. when user click send - then all recipients should be checked for encryption possibility ?

I think that delaying checks to the end aren't helping much. If it takes 2 minutes to send an email out, that's similarly bad.

Also, I'd the composer window to be up to date, and inform the user early whether encryption is possible or isn't possible, and which recipients are the cause.

Andrew, here is a test build, based on the latest beta 114 branch, that logs timing information to the error console. You can open the error console with hotkey command+shift+J

If you're trying to use the macOS experimental build, you'll have to run the xattr -cr command on the downloaded directory (use at your own risk).

Please run it with the defaults set, and see if the number of seconds that are logged match the delays that you experience.

I've added a setting mail.openpgp.fetch_pubkeys_from_gnupg which you could set to false. All other checking will still be kept. If you set that pref to false, and the delay is gone, we know that the delay is caused by fetching from gnupg.

linux64:
https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/AXZ58qcxQT-1qe8xySA_uQ/runs/0/artifacts/public/build/target.tar.bz2

win64:
https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/OMEa9JQdQSm1O7L0c3S76A/runs/0/artifacts/public/build/target.zip

macos:
https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/YyH2XJzeTAqgSKbhfTDI5Q/runs/0/artifacts/public/build/target.dmg

Interesting, it took me a few tries to reproduce the issue on the test build. On the other hand, it didn't reliably throw a warning about being unable to encrypt to test@example.org until I hit Send, so it's not clear if it's consistently performing the real-time check.

In any case, here's a timing trace from one occasion when I did manage to trigger the issue:

While creating services from category 'app-startup', service for entry 'OS Integration', contract ID '@mozilla.org/messenger/osintegration;1' does not implement nsIObserver.
1684513551666	addons.xpi	WARN	Checking /Applications/Thunderbird Daily.app/Contents/Resources/distribution/extensions for addons
Found 4 public keys and 0 secret keys (0 protected, 0 unprotected) RNPLib.jsm:548:15
Successfully loaded optional OpenPGP library libgpgme.dylib from additional standard locations GPGMELib.jsm:64:13
gpgme version: 1.19.0-unknown GPGMELib.jsm:236:15
services.settings: Failed to load last_modified.json: TypeError: NetworkError when attempting to fetch resource. Utils.sys.mjs:322
1684513595345	places	TRACE	FrecencyRecalculator :: Initializing Frecency Recalculator
1684513595345	places	TRACE	FrecencyRecalculator :: Arm frecency recalculation
1684513595346	places	TRACE	FrecencyRecalculator :: Got places-init-complete topic
1684513595382	places	TRACE	FrecencyRecalculator :: Origins alternative frecency clean up
Layout was forced before the page was fully loaded. If stylesheets are not yet loaded this may cause a flash of unstyled content. 2 aboutconfig.js:469:9
While creating services from category 'app-startup', service for entry 'OS Integration', contract ID '@mozilla.org/messenger/osintegration;1' does not implement nsIObserver.
Trying to load /Applications/Thunderbird Daily.app/Contents/MacOS/libotr.dylib OTRLib.sys.mjs:65:11
Trying to load libotr.dylib from system's standard library locations OTRLib.sys.mjs:65:11
Trying to load libotr.5.dylib from system's standard library locations OTRLib.sys.mjs:65:11
Trying to load libotr.dylib from system's standard library locations OTRLib.sys.mjs:65:11
Error: Cannot load required OTR library
    loadExternalOTRLib resource:///modules/OTRLib.sys.mjs:110
    init resource:///modules/OTRLib.sys.mjs:116
    once resource:///modules/OTR.sys.mjs:117
    init resource:///modules/OTR.sys.mjs:138
    init resource:///modules/OTRUI.sys.mjs:253
OTR.sys.mjs:126:15
time in seconds for checking OpenPGP keys for 0 recipients (foreground/blocking operation):  0 MsgComposeCommands.js:3451:13
time in seconds for fetching public keys for <REDACTED> from gnupg:  274.96 keyRing.jsm:1909:17
time in seconds for checking OpenPGP keys for 1 recipients (foreground/blocking operation):  275.096 MsgComposeCommands.js:3451:13
time in seconds for checking OpenPGP keys for 1 recipients (foreground/blocking operation):  0.015 MsgComposeCommands.js:3451:13
1684513878138	places	TRACE	FrecencyRecalculator :: Recalculate 50 frecency values
While creating services from category 'app-startup', service for entry 'OS Integration', contract ID '@mozilla.org/messenger/osintegration;1' does not implement nsIObserver.
1684513881016	places	TRACE	FrecencyRecalculator :: Got frecency-recalculation-needed topic
1684513881016	places	TRACE	FrecencyRecalculator :: Frecency recalculation requested
1684513881016	places	TRACE	FrecencyRecalculator :: Arm frecency recalculation 

There was one additional difference in the test build that I gave to you.
I had noticed that sometimes querying GPG would result in an error, and the lookup would stop. I fixed that one bug in the test build. I wonder if that somehow influenced your ability to reproduce the slowness - although it shouldn't, if you run into that scenario, it should rather completely stop to work.

So in your log, you had one OpenPGP key lookup of 275 seconds.

Could you please try to set mail.openpgp.fetch_pubkeys_from_gnupg to false with that test build?

With that, can you confirm that you no longer get those long delays?

I could also give you a test build that re-introduces the bug that I had fixed, to see if you can reproduce more frequently.

When you say "the lookup would stop" how would that present in the UI? I had to forcibly kill the test build on more than one occasion because it appeared to lock up forever...

I have been unable so far to replicate the delays with mail.openpgp.fetch_pubkeys_from_gnupg = false, however I have managed to lock up the test build consistently three times in a row with it set to true.

The trick appears to be to compose a mail to an encryptable recipient immediately after starting the app, this triggers the bug in the test build (almost!) every time. On the other hand, if I compose to a non-encrytpable recipient first, subsequent attempts only sometimes trigger the issue.

There also doesn't appear to be a consistent delay for the UI to lock up in the beta version. I've seen it return after 2 minutes, and I've seen it go well past 8.

(In reply to andrewg from comment #13)

I have been unable so far to replicate the delays with mail.openpgp.fetch_pubkeys_from_gnupg = false,

Ok, I think that confirms that the GnuPG interaction is responsible.

You might want to keep that at false.

I consider to add that pref to Thunderbird, and set it to false by default.

however I have managed to lock up the test build consistently three times in a row with it set to true.

I cannot tell what's happening, but it could be the interaction with the many certificates in GnuPG and the smartcard. I don't see an easy way for me to debug that. I know there's an environment variable available for GPGME for debugging, but it probably requires someone with expert knowledge to analyze what's going on in GnuPG world.

Well, in theory, there's one more thing we could trace.

We have the fetching from GPG, and we have importing candidate keys into TB storage. In theory it could be the latter, but somehow I doubt it's the latter. I could make a test build that measures both separately.

The trick appears to be to compose a mail to an encryptable recipient immediately after starting the app,

How did you do that? Click reply in a message? Or open fresh composer and type recipient?

this triggers the bug in the test build (almost!) every time. On the other hand, if I compose to a non-encrytpable recipient first, subsequent attempts only sometimes trigger the issue.
There also doesn't appear to be a consistent delay for the UI to lock up in the beta version. I've seen it return after 2 minutes, and I've seen it go well past 8.

I don't have an idea what could cause that difference. What worries me most is that you say "sometimes", which means it isn't really predictable what happens.

Based on your log, Thunderbird queried GPG only once. This means there isn't much we could optimize on the TB side. It's unacceptable to get this kind of delays. Until we find a way to somehow use better querying and avoid potential issues related to smartcards, I think we need to turn it off.

Depends on D178701

(In reply to Kai Engert (:KaiE:) from comment #14)

(In reply to andrewg from comment #13)

however I have managed to lock up the test build consistently three times in a row with it set to true.

I cannot tell what's happening, but it could be the interaction with the many certificates in GnuPG and the smartcard. I don't see an easy way for me to debug that. I know there's an environment variable available for GPGME for debugging, but it probably requires someone with expert knowledge to analyze what's going on in GnuPG world.

I doubt this is a smartcard issue - fetching public keys should never involve the smartcard, and I haven't seen it blink once during the testing process. It could easily be something else that's unusual about my configuration though.

We have the fetching from GPG, and we have importing candidate keys into TB storage. In theory it could be the latter, but somehow I doubt it's the latter. I could make a test build that measures both separately.

I doubt it also. If you have time to make a test build with the other bugfix removed, that sounds like a more promising avenue. There is a startup delay on the current test build that doesn't make sense from what you have described here...

The trick appears to be to compose a mail to an encryptable recipient immediately after starting the app,

How did you do that? Click reply in a message? Or open fresh composer and type recipient?

Open a fresh composer and start typing. I haven't tested replies yet, I had enough variables to consider already :-)

this triggers the bug in the test build (almost!) every time. On the other hand, if I compose to a non-encrytpable recipient first, subsequent attempts only sometimes trigger the issue.
There also doesn't appear to be a consistent delay for the UI to lock up in the beta version. I've seen it return after 2 minutes, and I've seen it go well past 8.

I don't have an idea what could cause that difference. What worries me most is that you say "sometimes", which means it isn't really predictable what happens.

Oh yes, that's been the most frustrating part. I've had issues before dealing with gpg's trustdb check requirement but this is happening too often for it to be that.

Based on your log, Thunderbird queried GPG only once. This means there isn't much we could optimize on the TB side. It's unacceptable to get this kind of delays. Until we find a way to somehow use better querying and avoid potential issues related to smartcards, I think we need to turn it off.

Would it be a better idea to sync in the background instead of on demand?

Pushed by mkmelin@iki.fi:
https://hg.mozilla.org/comm-central/rev/dfb7efd2d71a
Disable public key fetching from external GnuPG by default. r=mkmelin
https://hg.mozilla.org/comm-central/rev/5de23e1fcfbb
Avoid a potential exception when fetching public keys from external GnuPG. r=mkmelin

Comment on attachment 9335298 [details]
Bug 1833358 - Disable public key fetching from external GnuPG by default. r=mkmelin

[Approval Request Comment]
Regression caused by (bug #): 1762834
User impact if declined: some users may experience very long delays when using the optional feature to use external gnupg
Testing completed (on c-c, etc.):
Risk to taking this patch (and alternatives if risky): very low, it disables (by default) a recently added functionality, which was only active for users who are using a non-default configuration

Comment on attachment 9335299 [details]
Bug 1833358 - Avoid a potential exception when fetching public keys from external GnuPG. r=mkmelin

[Triage Comment]
Approved for beta.

Comment on attachment 9335298 [details]
Bug 1833358 - Disable public key fetching from external GnuPG by default. r=mkmelin

[Triage Comment]
Approved for beta.

Thunderbird 114.0b5:
ttps://hg.mozilla.org/releases/comm-beta/rev/a2f9a3998915
https://hg.mozilla.org/releases/comm-beta/rev/d7193a1b8c29