Re: Hostname resolution timing in DNS over HTTPS

On Wed, 4 Dec 2019, Kostas Antoniou via curl-users wrote:

> 1. curl --trace .\DOH_trace.txt --trace-time -w
> "\ntime_namelookup=%{time_namelookup}\n" --doh-url
> https://mydohserver/dns-query example.com
>
> According to the curl manpages, time_namelookup will provide the time from
> the start until the name is resolved. This is pretty clear when we use it
> for DNS over port 53 queries, however it is unclear if it applies to the DOH
> hostname (https://mydohserver /dns-query ) of the name to be resolved
> (example.com).

That's the time for the entire "name resolve" to complete and it should work
no matter how the name resolve is done. In your command line above, it'll show
how long time it took to resolve 'example.com'.

Is there anything that indicates that it doesn't work correctly? (DoH is still
fairly new in curl and I'm not sure how wide use and testing it has received
so there's certainly a risk that there are bugs lingering in there...)

> Furthermore, the timestamped traces show two DoH connections.

Yes, the first name resolves done for DoH will mostly be done using two
connections (instead of one connection with two streams) simply because curl
will prioritize getting the requests out rather than waiting with the second
to see if that can be done as a stream over the first connection.

> 1. curl --trace .\alternatemethod.txt --trace-time -w
> "\ntime_namelookup=%{time_namelookup}\n" --output .\output.txt --get --data
> "dns=q80BAAABAAAAAAAAA3d3dwdleGFtcGxlA2NvbQAAAQAB" --tls-max 1.3 --header
> "HOST: mydohserver/dns-query" --header
> "Content-Type:application/dns-message" https://mydohserver/dns-query

This way you measure the time it takes to resolve mydohserver (done with Do53,
I presume). It doesn't time the DoH request. Though running this entire
command line and time it would do pretty much that (although you then also get
the start-up time included etc.)

> Adding the values of time_namelookup and the last timestamp yields a value
> smaller than the name resolution of the 1st method (Comparisons done by
> running each command with a difference of 3 minutes from the other).

Your second case only makes a single DoH request so you're not testing the
same things. If you limit your first case to perhaps use IPv4 only they might
end up more similar.

> Furthermore, both methods take into account the time that will be needed for
> the connection setup and SSL handshakes, thus leading to times of hundreds
> of milliseconds (depending on the DoH host).

Yes, but DoH involves TLS so the first resolve over a fresh connection will
need some extra time. Even sometimes "hundreds of milliseconds" if your DoH
server is far away.

When doing multiple resolves, the connection can be reused though so
subsequent resolves don't have the same overhead.

> Any suggestions about how to collect the time from the moment the request
> leaves the client and until only the resolved hostname information come
> back?

This is then no longer the name resolving time, this is particular timing from
the HTTP request done for DoH.

Then I would suggest using the second method and maybe do 'time_starttransfer'
- 'time_connect' ?

-- 
  / daniel.haxx.se | Get the best commercial curl support there is - from me
                   | Private help, bug fixes, support, ports, new features
                   | https://www.wolfssl.com/contact/
-----------------------------------------------------------
Unsubscribe: https://cool.haxx.se/list/listinfo/curl-users
Etiquette:   https://curl.haxx.se/mail/etiquette.html