Benchmarking key listing: pubring.kbx vs pubring.gpg, 1.4 vs 2.1

[Guilhem Moulin]

TL;DR:
  * --list-keys is slower than (one would naively think) it should be
  * --list-sigs is quadratic (O(mn), where m is the total number of
    signatures, and n the number of keys in the keyring) due to the
    primary UID search on each signing key
  * --list-sigs with a keybox is too slow to be usable with large
    keyrings (probably a bug)


Hi list,

The new keybox format looks very appealing for large keyrings:

    “Random access to the keys is now really fast and keyrings with
     30000 keys and more are now easily possible.” —
     https://gnupg.org/faq/whats-new-in-2.1.html#keybox

However key listing doesn't seem to scale that well :-/  The timings
below are from my X60, Core™ Duo L2400 1.66GHz; I also run the benchmark
on a Core™ i7-4770S 3.10GHz, and while it's of course faster then the
general observation remains.

    $ gpg --version | head -1
    gpg (GnuPG) 1.4.18
    $ gpg2 --version | head -1
    gpg (GnuPG) 2.1.2

Starting with fresh copies of my keyring (containing 1245 keys) as
pubring.gpg and pubring.kbx:

    $ mkdir -m0700 /tmp/gnupg1 /tmp/gnupg2
    $ echo 'trust-model always' | tee /tmp/gnupg1/gpg.conf >/tmp/gnupg2/gpg.conf
    $ echo no-autostart >>/tmp/gnupg2/gpg.conf
    $ gpg2 --export | gpg --homedir /tmp/gnupg1 --import
    […]
    gpg: Total number processed: 1245
    gpg:               imported: 1245  (RSA: 979)
    $ gpg2 --export | gpg2 --homedir /tmp/gnupg2 --import
    […]
    gpg: Total number processed: 1245
    gpg:               imported: 1245
    $ stat --printf="%s %n\n" /tmp/gnupg1/pubring.gpg /tmp/gnupg2/pubring.kbx
    77957249 /tmp/gnupg1/pubring.gpg
    78184432 /tmp/gnupg2/pubring.kbx
    $ alias time="/usr/bin/time -f '%E (%U user, %S sys)  %Mk maxres'"

Doing a key listing takes roughly the same time on the fresh GnuPGHOMEs;
surprisingly enough 2.1 is slower than 1.4 on legacy public keyrings,
and it takes almost twice as long on my ~/.gnupg (which contains a
pubring.kbx but no pubring.gpg); I have no idea why.

    $ time gpg --homedir /tmp/gnupg1 --list-keys >/dev/null
    0:05.25 (5.09 user, 0.14 sys)  9084k maxres
    $ time gpg2 --homedir /tmp/gnupg2 --list-keys >/dev/null
    0:04.98 (4.84 user, 0.12 sys)  14360k maxres
    $ time gpg2 --homedir /tmp/gnupg1 --list-keys >/dev/null
    0:07.24 (7.14 user, 0.08 sys)  9580k maxres
    $ time gpg2 --options /tmp/gnupg2/gpg.conf --list-keys >/dev/null
    0:09.06 (8.94 user, 0.10 sys)  14264k maxres

I wonder where the bottleneck is anyway: listing slightly over a
thousands keys shouldn't take several seconds IMHO.  By comparison using
kbxutil(1) to dump the pubring.kbx is 10x faster:

    $ time kbxutil /tmp/gnupg2/pubring.kbx >/dev/null
    0:00.66 (0.60 user, 0.05 sys)  4888k maxres

Listing signatures is not really usable as it takes quite a while
already with the legacy pubring.gpg, and much much longer with the new
pubring.kbx.  (I didn't compute the asymptotic complexities exactly, but
as shown below the difference doesn't seem to be a constant factor.)

    $ time gpg --homedir /tmp/gnupg1 --list-sigs >/dev/null
    1:57.54 (83.55 user, 33.57 sys)  9264k maxres
    $ time gpg2 --homedir /tmp/gnupg2 --list-sigs >/dev/null
    2:24:34 (564.61 user, 8083.49 sys)  14936k maxres
    $ time gpg2 --homedir /tmp/gnupg2 --fast-list-mode --list-sigs >/dev/null
    0:05.97 (5.88 user, 0.07 sys)  14296k maxres
    $ time gpg2 --homedir /tmp/gnupg1 --list-sigs >/dev/null
    1:57.55 (89.15 user, 28.07 sys)  9740k maxres

The second timming is really odd: over 2h of system time?  Surely it
must be a bug.  The difference is already noticeable with a single key
0x39278DA8109E6244 with 1322 signatures, 953 for which the signing key
is also present in my keyring:

    $ gpg2 --with-colons --list-sigs 0x39278DA8109E6244 | grep -c ^sig:
    1322
    $ gpg2 --with-colons --list-sigs 0x39278DA8109E6244 | grep -Ec '^sig:([^:]*:){8}\[User ID not found\]:'
    369
    $ time gpg --homedir /tmp/gnupg1 --list-sigs 0x39278DA8109E6244 >/dev/null
    0:17.24 (11.72 user, 5.46 sys)  8852k maxres
    $ time gpg2 --homedir /tmp/gnupg2 --list-sigs 0x39278DA8109E6244 >/dev/null
    0:30.85 (3.26 user, 27.50 sys)  14564k maxres
    $ time gpg2 --homedir /tmp/gnupg1 --list-sigs 0x39278DA8109E6244 >/dev/null
    0:17.16 (12.58 user, 4.54 sys)  9608k maxres

Once again, I don't understand the difference between pubring.gpg and
pubring.kbx, especially why dumping the latter spends most of its time
in kernel mode.  But as I explained in a patch (unmerged as of 2.1.2)
last autumn [0], the fact that --list-sigs takes that long is because it
searches the primary UID of the signing keys, and as there is no caching
‘get_user_id’ is called *for every sig*, and at each iteration this
function walks through the *whole* keyring and packs the whole public
part of the signing key.

All in all, the algorithm for listing signatures seems highly
suboptimal.  In my earlier patch [0] I proposed to make --fast-list-mode
work better with --list-sigs (not printing the primary UID of the
signing keys hence skipping the quadratic search.  The primary UIDs
could later be retrieved by using --list-keys on the whole list of
signing keys without duplicates, albeit at the expense of extra memory
allocation.)  But as shown above kbxutil is capable of dumping the whole
pubring.kbx in half a second, dump from where all primary UIDs can be
retrieved, so I guess that with caching ‘get_user_id’ could be made much
faster ;-)

    $ kbxutil /tmp/gnupg2/pubring.kbx | grep -E '^(Uid|Key-Kid)\[0\]'

Or even better, since “random access to the keys is now really fast”,
presumably getting the pubkey off a keybox from its 64 bits key ID can
be done in sub-linear time (not sure, I couldn't find the specs for the
keybox format) via some kind of hash table.  Caching might not be needed
after all ;-)

-- 
Guilhem.

[0] http://lists.gnupg.org/pipermail/gnupg-devel/2014-September/028739.html
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 819 bytes
Desc: Digital signature
URL: </pipermail/attachments/20150225/da3150a7/attachment.sig>