Page MenuHome GnuPG

dirmngr error logs claim that HTTP GET requests are percent-escaped, but they are not
Open, WishlistPublic

Description

I'm pretending to be a keyserver to observe what dirmngr does.

in terminal A, i do:

nc -l -p 12345

in terminal B, i do:

gpg --keyserver 127.0.0.1:12345 --search `<dkg@fifthhorseman.net>`

in A, i see:

GET /pks/lookup?op=index&options=mr&search=<dkg@fifthhorseman.net> HTTP/1.0
Host: localhost:12345
Pragma: no-cache
Cache-Control: no-cache

If i then send back:

HTTP/1.1 502 bad gateway

then dirmngr closes the connection and logs:

2019-05-13 18:12:53 dirmngr[12603.6] error accessing 'http://127.0.0.1:12345/pks/lookup?op=index&options=mr&search=%3Cdkg%40fifthhorseman%2Enet%3E': http status 502
2019-05-13 18:12:53 dirmngr[12603.6] marking host dead due to a 502 (Bad Gateway)
2019-05-13 18:12:53 dirmngr[12603.6] marking host '127.0.0.1' as dead
2019-05-13 18:12:54 dirmngr[12603.6] host '127.0.0.1' marked as dead
2019-05-13 18:12:54 dirmngr[12603.6] command 'KS_SEARCH' failed: No keyserver available
2019-05-13 18:12:54 dirmngr[12603.6] DBG: chan_6 -> ERR 167772346 No keyserver available <Dirmngr>

note that the log claims to have percent-escaped the angle brackets (< and >) and the @ sign in the request, but on the wire it did not percent-escape them.

Some keyservers have problems if the client does not percent-escape, so this risks making those keyservers unusable.

No matter what dirmngr decides to do about percent-escaping on the wire, its logs should not claim to be doing percent-escaping if it is not actually doing percent-escaping.

Details

Version
2.2.15

Event Timeline

This is easy to explain: dirmngr receives already escaped data and that is what you see in the log. For proper parsing of the URI the escaping needs to be removed and only before sending the request the required escaping is applied. '@', '<', and '>' do not need to be escaped and thus you see them as they are.

I think you are saying that dirmngr receives the query term as escaped data in the assuan connection from the dirmngr client (typically, gpg, which itself decides how to percent-escape what it feeds into libassuan).

So dirmngr unescapes the data to know the query term in full. Subsequently, it assembles the URI to actually fetch, and in that process applies subtly different percent-escaping rules.

If the above description is correct, then the log message is still wrong, because it contains the URI, but it represents the URI based on the percent-escaping of the term sent via assuan. If dirmngr is going to log a URI, it should log the URI as the URI formed with its actual URI escaping rules.

werner triaged this task as Wishlist priority.May 16 2019, 10:52 AM

This requires too much changes and does not reflect the reality. It actually makes debugging harder for us.

"requires too much changes" i can understand.

how does "not reflect reality" work here? I'm asking for the log files to reflect reality.

How does it make debugging harder? the fact that the logs are inaccurate actually concretely made debugging harder for me just a couple days ago as i was tracking down a bug in hagrid.

If the story is "we think it's more important to represent what we got on the wire via libassuan" then please, represent it that way in the logs, and don't claim to put a URL in the logs. That shouldn't be a hard change to make. But If you're going to put a URL in the logs, please put the URL that dirmngr actually uses.

I agree with @dkg here.

Also @werner: Please do not use "wishlist" as "wontfix but I don't feel like arguing about it". This clutters our tracker.