Dns resolution unexpected timeout

[oschaaf]

Over at istio/tools#692, when running the istio benchmark in gcloud kubernetes, somehow Nighthawk is not able to resolve DNS when attempting to benchmark fortioserver. [1]
Dumping some context / thoughts:

• The test consists of two pods in distinct nodes. This doesn't happen with minikube which only runs a single node.
• Testing with nslookup and ping, other pods seem able to perform dns resolution, though nslookup outputs a weird line.
• It seems that this doesn't happen when Istio is taken out of the equation, though I would need to double check this to make sure I didn't have a mistake in that specific test back then.

Chances are something is off with NH, but for completeness also listing other potential causes:

• Alpine, in which our docker image is based (frolvlad/alpine-glibc) seems to have trouble with dns resolution in certain scenarios: Apparent DNS failure in Docker image alpine:3.8, nslookup: can't resolve '(null)' gliderlabs/docker-alpine#476
• Envoy also seems to have an edge case: dns: DnsResolverImpl keeps using a "broken" c-ares channel envoy#4543

[1]

[08:40:41.427198][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 5000 milliseconds
[08:40:41.427236][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 5000 milliseconds
[08:40:41.427249][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 5000 milliseconds
[08:40:46.432351][156][D] [external/envoy/source/common/network/dns_impl.cc:126] DNS request timed out 1 times
[08:40:46.432754][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 0 milliseconds
[08:40:46.432860][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 5000 milliseconds
[08:40:46.432973][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 5000 milliseconds
[08:40:46.433031][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 5000 milliseconds
[08:40:51.427363][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 5 milliseconds
[08:40:51.427854][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 4 milliseconds
[08:40:51.427877][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 4 milliseconds
[08:40:51.427883][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 10000 milliseconds
[08:40:51.427913][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 10000 milliseconds
[08:40:51.427918][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 10000 milliseconds
[08:41:01.427875][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 0 milliseconds
[08:41:01.428021][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 0 milliseconds
[08:41:01.428046][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 0 milliseconds
[08:41:01.428056][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 20000 milliseconds
[08:41:01.428080][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 20000 milliseconds
[08:41:01.428086][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 20000 milliseconds
[08:41:11.428791][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 10000 milliseconds
[08:41:11.428954][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 9999 milliseconds
[08:41:11.428967][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 9999 milliseconds
[08:41:11.428972][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 40000 milliseconds
[08:41:11.428997][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 40000 milliseconds
[08:41:11.429009][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 40000 milliseconds
[08:41:21.429065][156][T] [external/envoy/source/common/network/dns_impl.cc:166] Setting DNS resolution timer for 30000 milliseconds
[08:41:21.429147][156][W] [source/common/uri_impl.cc:104] Could not resolve 'fortioserver'

[oschaaf]

While writing the summary above, it occurred to me that we might be using tcp for dns lookups, whereas nslookup& ping might be using udp. This could explain the different behavior.

Checking the code base:

  virtual Network::DnsResolverSharedPtr
  createDnsResolver(const std::vector<Network::Address::InstanceConstSharedPtr>& resolvers,
                    bool use_tcp_for_dns_lookups) PURE;

Indeed Nighthawk's UriImpl passes in true for the second argument.

[oschaaf]

Confirmed: switching dns to use UDP resolved the issue over at istio/tools/perf/benchmark