Page MenuHome GnuPG
Create Task
Maniphest T3741

dirmngr, GnuPG: WKD lookup unexpectedly slow
Closed, ResolvedPublic
Actions

Description

The WKD lookup is unexpectedly slow. For me it takes from 2seconds to 10 seconds. I don't understand why it is so slow if it hits an existing / published key.

I would be interested if it is just me or if this is a general problem. As it is very easy to test please note the time it takes for you to fetch my key when you comment.

My test:

  1. Empty Homdir with dirmngr and gpg-agent startup:
aheinecke@esus ~> export GNUPGHOME=$(mktemp -d)                                                                
aheinecke@esus ~> time gpg --verbose --locate-key aheinecke@intevation.de                                      
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: keybox '/tmp/tmp.GP5Gdz9nOI/pubring.kbx' created
gpg: /tmp/tmp.GP5Gdz9nOI/trustdb.gpg: trustdb created
gpg: using pgp trust model
gpg: error retrieving 'aheinecke@intevation.de' via Local: No public key
gpg: no running Dirmngr - starting '/opt/gnupg/bin/dirmngr'
gpg: waiting for the dirmngr to come up ... (5s)
gpg: connection to the dirmngr established
gpg: pub  rsa3072/1FDF723CF462B6B1 2015-12-08  Andre Heinecke <aheinecke@gnupg.org>
gpg: key 1FDF723CF462B6B1: public key "Andre Heinecke <aheinecke@intevation.de>" imported
gpg: no running gpg-agent - starting '/opt/gnupg/bin/gpg-agent'
gpg: waiting for the agent to come up ... (5s)
gpg: connection to agent established
gpg: Total number processed: 1
gpg:               imported: 1
gpg: 0 keys processed (0 validity counts cleared)
gpg: no ultimately trusted keys found
gpg: auto-key-locate found fingerprint 94A5C9A03C2FE5CA3B095D8E1FDF723CF462B6B1
gpg: automatically retrieved 'aheinecke@intevation.de' via WKD
pub   rsa3072 2015-12-08 [SC] [expires: 2025-12-05]
      94A5C9A03C2FE5CA3B095D8E1FDF723CF462B6B1
uid           [ unknown] Andre Heinecke <aheinecke@intevation.de>
sub   rsa3072 2015-12-08 [E] [expires: 2025-12-05]
sub   rsa3072 2015-12-08 [A] [expires: 2025-12-05]
sub   ed25519 2017-02-13 [S]
sub   ed25519 2017-02-13 [A]
sub   cv25519 2017-02-13 [E] [revoked: 2017-02-23]

gpg --verbose --locate-key aheinecke@intevation.de  0.03s user 0.00s system 0% cpu 7.752 total
  1. Same Homedir gpg-agent and dirmngr already running:
aheinecke@esus ~> time gpg --verbose --auto-key-locate clear,nodefault,wkd --locate-key aheinecke@intevation.de
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: using pgp trust model
gpg: error retrieving 'aheinecke@intevation.de' via None: No public key
gpg: pub  rsa3072/1FDF723CF462B6B1 2015-12-08  Andre Heinecke <aheinecke@gnupg.org>
gpg: key 1FDF723CF462B6B1: "Andre Heinecke <aheinecke@intevation.de>" not changed
gpg: Total number processed: 1
gpg:              unchanged: 1
gpg: auto-key-locate found fingerprint 94A5C9A03C2FE5CA3B095D8E1FDF723CF462B6B1
gpg: automatically retrieved 'aheinecke@intevation.de' via WKD
pub   rsa3072 2015-12-08 [SC] [expires: 2025-12-05]
      94A5C9A03C2FE5CA3B095D8E1FDF723CF462B6B1
uid           [ unknown] Andre Heinecke <aheinecke@intevation.de>
sub   rsa3072 2015-12-08 [E] [expires: 2025-12-05]
sub   rsa3072 2015-12-08 [A] [expires: 2025-12-05]
sub   ed25519 2017-02-13 [S]
sub   ed25519 2017-02-13 [A]
sub   cv25519 2017-02-13 [E] [revoked: 2017-02-23]

gpg --verbose --auto-key-locate clear,nodefault,wkd --locate-key   0.02s user 0.00s system 0% cpu 4.928 total
aheinecke@esus ~> time gpg --verbose --auto-key-locate clear,nodefault,wkd --locate-key aheinecke@intevation.de
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: using pgp trust model
gpg: error retrieving 'aheinecke@intevation.de' via None: No public key
gpg: pub  rsa3072/1FDF723CF462B6B1 2015-12-08  Andre Heinecke <aheinecke@gnupg.org>
gpg: key 1FDF723CF462B6B1: "Andre Heinecke <aheinecke@intevation.de>" not changed
gpg: Total number processed: 1
gpg:              unchanged: 1
gpg: auto-key-locate found fingerprint 94A5C9A03C2FE5CA3B095D8E1FDF723CF462B6B1
gpg: automatically retrieved 'aheinecke@intevation.de' via WKD
pub   rsa3072 2015-12-08 [SC] [expires: 2025-12-05]
      94A5C9A03C2FE5CA3B095D8E1FDF723CF462B6B1
uid           [ unknown] Andre Heinecke <aheinecke@intevation.de>
sub   rsa3072 2015-12-08 [E] [expires: 2025-12-05]
sub   rsa3072 2015-12-08 [A] [expires: 2025-12-05]
sub   ed25519 2017-02-13 [S]
sub   ed25519 2017-02-13 [A]
sub   cv25519 2017-02-13 [E] [revoked: 2017-02-23]

gpg --verbose --auto-key-locate clear,nodefault,wkd --locate-key   0.03s user 0.00s system 0% cpu 5.628 total
  1. Using wget to show that the connection is fast:
aheinecke@esus ~> time wget -O - https://intevation.de/.well-known/openpgpkey/hu/g8td9rsyatrazsoiho37j9n3g5ypp34h | gpg --import
--2018-01-17 08:42:08--  https://intevation.de/.well-known/openpgpkey/hu/g8td9rsyatrazsoiho37j9n3g5ypp34h
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!
Resolving intevation.de (intevation.de)... 212.95.107.144
Connecting to intevation.de (intevation.de)|212.95.107.144|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 18845 (18K)
Saving to: ‘STDOUT’

-                            100%[==============================================>]  18.40K  --.-KB/s    in 0.06s   

2018-01-17 08:42:09 (324 KB/s) - written to stdout [18845/18845]

gpg: key 1FDF723CF462B6B1: 40 signatures not checked due to missing keys
gpg: key 1FDF723CF462B6B1: "Andre Heinecke <aheinecke@intevation.de>" 3 new user IDs
gpg: key 1FDF723CF462B6B1: "Andre Heinecke <aheinecke@intevation.de>" 33 new signatures
gpg: Total number processed: 1
gpg:           new user IDs: 3
gpg:         new signatures: 33
gpg: no ultimately trusted keys found
wget -O -   0.03s user 0.00s system 9% cpu 0.333 total
gpg --import  0.02s user 0.00s system 5% cpu 0.364 total

Details

Version
2.2.5-beta9

Event Timeline

• aheinecke created this task.Jan 17 2018, 8:48 AM
• werner added a subscriber: • werner.Jan 17 2018, 9:19 AM

I can't replicate it here. With my key it takes
real 0m0.346s
user 0m0.080s
sys 0m0.004s
and for your key it takes a few 10ms longer (more hops). Is one of your DNS responder failing? Can you please run dirmngr with --debug dns ?

• aheinecke closed this task as Resolved.Jan 17 2018, 12:28 PM
• aheinecke claimed this task.

Indeed with debug dns I can see that what takes so long is the resolve_dns_name. After the debug output prints that line the key comes nearly instant.

aheinecke@esus ~/a/k/s/g/src> dirmngr --debug dns
dirmngr[18480]: Note: no default option file '/tmp/tmp.Vx4GwJLFxL/dirmngr.conf'
dirmngr[18480]: NOTE: this is a development version!
dirmngr[18480]: enabled debug flags: dns
dirmngr[18480]: error opening '/tmp/tmp.Vx4GwJLFxL/dirmngr_ldapservers.conf': No such file or directory
dirmngr[18480.0]: permanently loaded certificates: 168
dirmngr[18480.0]:     runtime cached certificates: 0
dirmngr[18480.0]:            trusted certificates: 168 (167,0,0,1)
# Home: /tmp/tmp.Vx4GwJLFxL
# Config: [none]
OK Dirmngr 2.2.5-beta9 at your service
WKD_GET aheinecke@intevation.de
dirmngr[18480.0]: DBG: dns: libdns initialized (tor mode)
dirmngr[18480.0]: DBG: dns: getsrv(_openpgpkey._tcp.intevation.de) -> 0 records
S SOURCE https://intevation.de
dirmngr[18480.0]: number of system provided CAs: 167
dirmngr[18480.0]: DBG: dns: libdns initialized (tor mode)
dirmngr[18480.0]: DBG: dns: resolve_dns_name(intevation.de): Success
.... here comes the key

And when I put no-use-tor in my config it's quick.

So resolved -> this makes it clear to me why it is slow.