FWIW: I am not anymore very convinced of our tofu code. it leaks too many information because it tracks and stored all signature verification. The model is further way too complicated and the SQL used will eventually lead to a resource problem. Maybe doing Tofu stuff in the frontend is a better idea and get rid of all the history processing which works only for fresh mails and not for data verification.

Yes it is set to tofu+pgp. Is it now possible to change the trust-model on context based?

Thanks for the report, since you are using it on the command line and it works I assume that trust-model is set to tofu+pgp? Because in the Test code there is no context flag for tofu+pgp trust model.

Thanks for the report, since you are using it on the command line and it works I assume that trust-model is set to tofu+pgp? Because in the Test code there is no context flag for tofu+pgp trust model.

I verified that manually putting the DB in WAL mode also resolved this issue, since writers don't block readers in WAL mode.

Thanks @werner for applying the patch. Closing here, since I have been using that patch for several weeks now without ever encountering the bug again.

The problem seems to have to do with the locking of the TOFU database.

Still trying to pinpoint the bug, but I am afraid I am stuck.

I did a few more tests and here are some more observations:

One of these TOFU bugs. Thanks for the good bug report.

Done in 274609ba.

Time to say good bye my dear bug.

I'm marking this as resolved since I think is fixed. Please reopen if this is
not the case.

This should be fixed in 027b81b35fe36692005b8dba22d9eb2db05e8c80.

To be clear the initial output is not wrong. At the time the information is
initially requested, the message has not yet been processed.

Anyway, I think I'm working on a fix so this is a non-issue.

Note that each of these outputs is preceded by a KEY_CONSIDERED lined (for the
same key). Since the TOFU conflict information is per key, I'd expect an
implementation to say: Oh, there is already some conflict information for key X.
This must be a more up to date version, so I'll delete that first instead of
appending to it. Is this an unreasonable expectation?

In my Opinion it is. There is a technical, (i guess) unintentional, reason for
the multiple outputs, they
don't convey useful information. So I would consider this Output a Bug and
implementations
working like you describe it to be a workaround for that bug.

Getting firs wrong information and later updating it with the correct
information makes implementations
more complicated and error prone and currently is not handled in GPGME.

Also in GPGME we just want to figure out the TOFU Info for all the UID's of the
key used
to check the signature. We don't want information about conflicting keys. We need
a reliable way to filter this out. So I have a patch that ignores all TOFU_USER
lines
that don't match the fingerprint of the signature but still that breaks because
the "Update"
is not handled.

KEY_CONSIDERED is orthogonal to the TOFU stats. Thus GPGME thus not evaluate it
to learn about the TOFU state.

It's true that the user is listed 4 times, but this is because tofu.c:get_trust
is called four times. For instance, the first time it is called to show the
"gpg: Good signature from "tofu_conflict@example.com" [marginal]" line, and the
second time is it called to register the signature (tofu_register_signature).
This also explains why the signature count increases between the first and
second versions.

Note that each of these outputs is preceded by a KEY_CONSIDERED lined (for the
same key). Since the TOFU conflict information is per key, I'd expect an
implementation to say: Oh, there is already some conflict information for key X.
This must be a more up to date version, so I'll delete that first instead of
appending to it. Is this an unreasonable expectation?

It should be possible to change the behavior to only output the TOFU_STATS lines
if a TOFU_STATS_LONG line is also output (but I need to think about it some
more). Would this be better?

In general, parallel operations aren't great, but I find that such bad
performance surprising.

If you update a key, only that key's effective policy is rechecked, not all
keys. But, the effective policy of conflicting keys is always rechecked.

Duplicate of T2859

This issue has also been reported in https://bugs.gnupg.org/gnupg/Issue2859

Werner replied there and I agree with his conclusion.

While testing with tofu enabled I sometimes see that some actions take very
long. (>1minute)

Like importing a key in Kleopatra where Kleopatra does an import and starts a
keylist afterwards / in parallel.

I'll try to reproduce this on the command line. Just doing a simple import on
the command line is quick.

Do you have any hint what can take so long?
Like a trigger that would cause a rechecks for cross signatures?

This should be fixed in: 2f27cb12e30c9f6e780354eecc3ff0039ed52c63 .

On Windows especially the initial keylist is very slow, subsequent keylists are
okish (less then 10 seconds) I don't think it's as big a problem anymore.
Listing a specific key is ~100ms. And that is with a large keyring (~18mb) on a
VM with a fairly slow harddisk.

For me this would be good enough to use tofu on windows. So it can be resolved
if you do not think the performance (especially of the initial listing) can be
improved or should have been better.

PS C:\Users\aheinecke> Measure-Command -Expression { gpg --no-auto-check-trustdb
--with-colons --trust-model tofu --list-keys --with-colons > $null }
gpg: NOTE: THIS IS A DEVELOPMENT VERSION!
gpg: It is only intended for test purposes and should NOT be
gpg: used in a production environment or with production keys!
gpg: please do a --check-trustdb
gpg: public key 60041E4EC03449C4 is 39 seconds newer than the signature
gpg: public key 60041E4EC03449C4 is 39 seconds newer than the signature

Days : 0
Hours : 0
Minutes : 1
Seconds : 14
Milliseconds : 785
Ticks : 747854659
TotalDays : 0.000865572521990741
TotalHours : 0.0207737405277778
TotalMinutes : 1.24642443166667
TotalSeconds : 74.7854659
TotalMilliseconds : 74785.4659

PS C:\Users\aheinecke> Measure-Command -Expression { gpg --no-auto-check-trustdb
--with-colons --trust-model tofu --list-keys --with-colons > $null }
gpg: NOTE: THIS IS A DEVELOPMENT VERSION!
gpg: It is only intended for test purposes and should NOT be
gpg: used in a production environment or with production keys!
gpg: please do a --check-trustdb
gpg: public key 60041E4EC03449C4 is 39 seconds newer than the signature

Days : 0
Hours : 0
Minutes : 0
Seconds : 7
Milliseconds : 812
Ticks : 78128420
TotalDays : 9.0426412037037E-05
TotalHours : 0.00217023388888889
TotalMinutes : 0.130214033333333
TotalSeconds : 7.812842
TotalMilliseconds : 7812.842

PS C:\Users\aheinecke> Measure-Command -Expression { gpg --no-auto-check-trustdb
--with-colons --trust-model pgp --list-keys --with-colons > $null }
gpg: NOTE: THIS IS A DEVELOPMENT VERSION!
gpg: It is only intended for test purposes and should NOT be
gpg: used in a production environment or with production keys!
gpg: public key 60041E4EC03449C4 is 39 seconds newer than the signature

Days : 0
Hours : 0
Minutes : 0
Seconds : 1
Milliseconds : 369
Ticks : 13697177
TotalDays : 1.58532141203704E-05
TotalHours : 0.000380477138888889
TotalMinutes : 0.0228286283333333
TotalSeconds : 1.3697177
TotalMilliseconds : 1369.7177

PS C:\Users\aheinecke> gpg --version
gpg (GnuPG) 2.1.17-beta30
libgcrypt 1.7.3

Home: C:/Users/aheinecke/AppData/Roaming/gnupg
Supported algorithms:
Pubkey: RSA, ELG, DSA, ECDH, ECDSA, EDDSA
Cipher: IDEA, 3DES, CAST5, BLOWFISH, AES, AES192, AES256, TWOFISH,

CAMELLIA128, CAMELLIA192, CAMELLIA256

Hash: SHA1, RIPEMD160, SHA256, SHA384, SHA512, SHA224
Compression: Uncompressed, ZIP, ZLIB, BZIP2

Fixed in 03a65a5. The time for doing a tofu --with-tofu-info --with-colons
listing is now similar to doing a pgp listing.

Please reopen if there are still unresolved issues.

$ time gpg2 --with-tofu-info --with-colons --no-auto-check-trustdb
--no-default-keyring --keyring /usr/share/keyrings/debian-keyring.gpg
--trust-model pgp -k >/dev/null
gpg: Note: signatures using the MD5 algorithm are rejected

real 0m1.972s
user 0m1.940s
sys 0m0.028s
$ time gpg2 --with-tofu-info --with-colons --no-auto-check-trustdb
--no-default-keyring --keyring /usr/share/keyrings/debian-keyring.gpg
--trust-model tofu -k >/dev/null
gpg: Note: signatures using the MD5 algorithm are rejected

real 0m2.252s
user 0m2.172s
sys 0m0.020s

I suspect that the problem is the same as T2817.

Andre and I chatted about this issue offline, and I now understand what the
problem is. The TOFU_STATS status line (as documented in gnupg/doc/DETAILS) has
a "validity" field that is a number between 0 and 4 where 1 to 4 indicate how
confident we are that the binding is valid, and 0 means that the binding has an
unresolved conflict. The problem that Andre has observed is that this field is
not set to 0 if there is a conflict.

As a matter of fact, the validity field is never set to 0. This is completely
redundant as the same TOFU_STATS status line has a policy parameter, which is
"ask" if there is a conflict. Moreover, overloading this field in this way
causes a loss of information. Just because there is a conflict doesn't mean
that gpg shouldn't report the validity, or that the client can't made use of it.

Thus, in my opinion, the right thing to do is to simply use the <policy> field
to detect whether there is a conflict. Werner has suggested that this is wrong,
but I couldn't follow his logic. Thus, I'm adding him to the nosy list and I
hope he can clarify what he wants here.

Sorry for the delay in getting back to you on this issue. I think you mean they
have undefined trust (that's what I get here). Undefined trust means "not
enough information for calculation" (from trustdb.h).

Can you clarify what you mean by validity conflict?

Hi Andre,

Thanks for following up. I seem to be able to reproduce the first part of your
issue here and I'm looking in to it.

Thanks,
Neal

Sry I accidentally posted an incomplete message with T2812 (aheinecke on Oct 31 2016, 05:08 PM / Roundup) (I used itsalltext
and postet a wrong version).

I wanted to write:

On the command line it's looking good. The second keylist is also down to 5
seconds on Windows.

But used from gpgme it still takes about a minute. If you add --with-colons and
slow down system calls by using strace you can also see this on GNU/Linux:

~> time strace gpg2 --no-default-keyring \

--keyring /usr/share/keyrings/debian-keyring.gpg \
--no-auto-check-trustdb --trust-model pgp \
--with-colons -k >/dev/null 2>&1

2.26s user 0.40s system 102% cpu 2.601 total
~> time strace gpg2 --no-default-keyring \

--keyring /usr/share/keyrings/debian-keyring.gpg \
--no-auto-check-trustdb --trust-model tofu \
--with-colons -k >/dev/null 2>&1

21.43s user 24.47s system 108% cpu 42.451 total

On Windows it's:

PS C:\Users\aheinecke> Measure-Command -Expression { gpg --no-auto-check-trustdb
--trust-model tofu --list-keys > $null
}
TotalSeconds : 7.0945596

PS C:\Users\aheinecke> Measure-Command -Expression { gpg --no-auto-check-trustdb
--with-colons --trust-model tofu --lis
t-keys > $null }
TotalSeconds : 56.0914993

PS C:\Users\aheinecke> Measure-Command -Expression { gpg --no-auto-check-trustdb
--with-colons --trust-model pgp --list
-keys > $null }
TotalSeconds : 1.4855689

I'm also still seeing decryption blocked on Windows while a keylist
--with-colons runs.

I wonder if we should generally check out performance of reading the keyring on
Windows
mabye we could genrally improve it so that it's better cached by Windows.

No both have unknown trust.

7a634e48b13c5d5d295b8fed9b429e1b2109a333 should fix the contention issue.
Please let me know if you are still having issues.