kubernetes: Using nginx 1.9 DNS resolver output error periodically

Hello guys,

Contrary to what I wrote in my last message, I am now almost sure that this is a k8s / docker issue. I can confirm that nginx is performing DNS requests as expected, but is not receiving answers back. This seems to be caused by a wrong configuration of the iptables DNAT of the Node for iptables-based k8s Services when a Pod is re-created.

How to reproduce (k8s v1.3.6):

• Started a Pod and Service for service fooservice with type ClusterIP
• Make sure kube-dns works, ClusterIP is 10.0.0.10, EndPoint in my case is 10.244.167.4:53 on both TCP and UDP
• Configure a nginx LoadBalancer Service using a custom resolver pointing to the ClusterIP of the kube-dns service:

resolver 10.0.0.10 valid=10s ipv6=off;
resolver_timeout 5s;

• A tcpdump shows that nginx is sending DNS requests with the configured valid parameter frequency to resolve fooservice (requests to nginx from outside of the k8s cluster):

# Requests to DNS server 10.0.0.10:53 for fooservice.default.svc.cluster.local
# return A record 10.0.51.97
# Notice source port 54993
<nginx-pod>$ tcpdump -n udp port 53
11:47:33.348227 IP 10.244.156.6.54993 > 10.0.0.10.53: 28818+ A? fooservice.default.svc.cluster.local. (54)
11:47:33.348954 IP 10.0.0.10.53 > 10.244.156.6.54993: 28818* 1/0/0 A 10.0.51.97 (70)
11:47:44.380677 IP 10.244.156.6.54993 > 10.0.0.10.53: 16589+ A? fooservice.default.svc.cluster.local. (54)
11:47:44.381096 IP 10.0.0.10.53 > 10.244.156.6.54993: 16589 1/0/0 A 10.0.51.97 (70)
11:47:55.707674 IP 10.244.156.6.54993 > 10.0.0.10.53: 9368+ A? fooservice.default.svc.cluster.local. (54)
11:47:55.708095 IP 10.0.0.10.53 > 10.244.156.6.54993: 9368 1/0/0 A 10.0.51.97 (70)

• We also see forwarded traffic on the Node where the nginx Pod runs:

# kube-dns service EndPoint is 10.244.167.4, requests and responses work
<node-of-nginx-pod>$ tcpdump -n udp port 53
11:47:33.348245 IP 10.244.156.6.54993 > 10.244.167.4.53: 28818+ A? fooservice.default.svc.cluster.local. (54)
11:47:33.348940 IP 10.244.167.4.53 > 10.244.156.6.54993: 28818* 1/0/0 A 10.0.51.97 (70)
11:47:44.380694 IP 10.244.156.6.54993 > 10.244.167.4.53: 16589+ A? fooservice.default.svc.cluster.local. (54)
11:47:44.381086 IP 10.244.167.4.53 > 10.244.156.6.54993: 16589 1/0/0 A 10.0.51.97 (70)
11:47:55.707693 IP 10.244.156.6.54993 > 10.244.167.4.53: 9368+ A? fooservice.default.svc.cluster.local. (54)
11:47:55.708087 IP 10.244.167.4.53 > 10.244.156.6.54993: 9368 1/0/0 A 10.0.51.97 (70)

• We now delete the kube-dns pod, we make sure it is re-created, ClusterIP remains at 10.0.0.10, EndPoint is now 10.244.168.5:53
• At this point, external requests to load-balanced fooservice via nginx start to fail (nginx logs):

2016/11/07 12:29:23 [error] 593#593: *71503 fooservice.default.svc.cluster.local could not be resolved (110: Operation timed out), client: 172.31.58.9, server: <edited>, request: "GET /v1/foo/actuator/info HTTP/1.1", host: "<edited>"
172.31.58.9 - - [07/Nov/2016:12:29:23 +0000] "GET /v1/foo/actuator/info HTTP/1.1" http 502 179 "-" "curl/7.45.0" 5.001 up - .

• If we check the tcpdump on the Pod, we see that there is no answer to the nginx DNS requests:

# Notice the source port of DNS requests from nginx stays as before on 54993
12:29:26.403433 IP 10.244.156.6.54993 > 10.0.0.10.53: 58458+ A? fooservice.default.svc.cluster.local. (54)
12:29:33.156744 IP 10.244.156.6.54993 > 10.0.0.10.53: 31120+ A? fooservice.default.svc.cluster.local. (54)
12:29:38.947385 IP 10.244.156.6.54993 > 10.0.0.10.53: 37641+ A? fooservice.default.svc.cluster.local. (54)
12:29:44.731240 IP 10.244.156.6.54993 > 10.0.0.10.53: 51226+ A? fooservice.default.svc.cluster.local. (54)
...

• The same tcpdump on the Node shows no answers as well, but now the node is trying to forward the requests to the ClusterIP 10.0.0.10, not the endpoint!. My assumption is that at this point the iptables rules in the Node are not correctly cleaned by kube-proxy, and the rule for port 54993 is stalled:

# Notice the source port stays constant at 54993
12:29:26.403448 IP 10.244.156.6.54993 > 10.0.0.10.53: 58458+ A? fooservice.default.svc.cluster.local. (54)
12:29:33.156764 IP 10.244.156.6.54993 > 10.0.0.10.53: 31120+ A? fooservice.default.svc.cluster.local. (54)
12:29:38.947401 IP 10.244.156.6.54993 > 10.0.0.10.53: 37641+ A? fooservice.default.svc.cluster.local. (54)
12:29:44.731255 IP 10.244.156.6.54993 > 10.0.0.10.53: 51226+ A? fooservice.default.svc.cluster.local. (54)

• Requests from the nginx pod using dig or nslookup do work (possibly because it uses some other dynamic source UDP port and this has no previous mapping in iptables).
• Now we can solve the nginx issues by either restarting nginx or reloading its configuration (which effectively uses another source port for the DNS packets), and then the resolver works again.
• It is worth noting that there also seems to be a timeout on the iptables DNAT, so if we wait long enough not making requests to nginx, at some point it will start working again. Of course this is not acceptable in production 😃

I have found several open issues in the k8s lists pointing in this direction: https://github.com/kubernetes/kubernetes/issues/19029 https://github.com/kubernetes/kubernetes/issues/31983 https://github.com/docker/docker/issues/8795

Some of the bug reports on the other tickets also mention that it might be possible to trigger the timeout/refresh of the DNAT Node ports using conntrack on the Node, but I haven’t still tried.

same issue, and resolved by this: https://stackoverflow.com/a/37569397/2526528 .

spec:
  containers:
    - name: nginx
      image: "nginx:1.10.0"
      ports:
        - containerPort: 8080
          name: "external"
          protocol: "TCP"
    - name: dnsmasq
      image: "janeczku/go-dnsmasq:release-1.0.5"
      args:
        - --listen
        - "127.0.0.1:53"
        - --default-resolver
        - --append-search-domains
        - --hostsfile=/etc/hosts
        - --verbose

then I also had to disable the ipv6 for the resolver in nginx:

location ~ ^/(.+)$ {
        resolver 127.0.0.1:53 ipv6=off;
        set $backend "http://$1:80";
        proxy_pass $backend;
}

Interesting observation testing locally with minikube.

I have an nginx pod with an endpoint with proxy_pass to another pod (via service_name.default.svc.cluster.local). There is a single kube-dns pod.

I access nginx endpoint - it works fine.

Now, if I delete the dns pod and wait for the new dns pod to be Ready, and then access the nginx endpoint again - it works!

But, if I delete the dns pod, but access nginx endpoint before the dns pod is Ready, it fails! And it keeps failing even after the dns pod becomes Ready.

I resolved this by coredns docker ： my nginx and coredns are all deploy on host

step1: config Corefile in Corefile maybe you should change k8s master config refer: https://coredns.io/plugins/kubernetes/

sudo mkdir /etc/coredns;
sudo tee /etc/coredns/Corefile   <<-'EOF'
.:53 {
    log
    errors
    health
    kubernetes cluster.local in-addr.arpa ip6.arpa {
       endpoint http://172.31.88.71:8080
       pods insecure
       upstream
       fallthrough in-addr.arpa ip6.arpa
       ttl 30
    }
    forward . /etc/resolv.conf
    cache 30
    loop
    reload
    loadbalance
}
EOF

step2:config docker and then start it

tee coreos.sh   <<-'EOF'
 docker run --restart=always  -idt --name coredns \
 -v /etc/coredns/Corefile:/etc/coredns/Corefile \
 -v /home/ec2-user/.kube/config:/etc/coredns/kubeconfig \
 -p 53:53/udp \
 coredns/coredns:1.6.9 \
 -conf /etc/coredns/Corefile
EOF

step3: config nginx and then reload

resolver 127.0.0.1 valid=60s ipv6=off;

@xingxing9688 I haven’t had a chance to test this again, but by the commit closing this issue, seems it was fixed in k8s 1.7+

@dlouzan great investigation! I have also tried to understand the same issue, and the point I’ve reached so far is watching the iptables entries related to kube-dns, which look like this during ‘normal’ state: (notice the 3 types of entries for the 3 different ips of the dns pods, as well as two “KUBE-SVC…” entries pointing to the kube-dns ClusterIP - 10.0.220.2)

# calling iptables -t nat -L -v | grep kube-dns
    0     0 KUBE-MARK-MASQ  all  --  any    any     10.1.9.135           anywhere             /* kube-system/kube-dns:dns-tcp */
    0     0 DNAT       tcp  --  any    any     anywhere             anywhere             /* kube-system/kube-dns:dns-tcp */ tcp to:10.1.9.135:53
    0     0 KUBE-MARK-MASQ  all  --  any    any     10.1.9.135           anywhere             /* kube-system/kube-dns:dns */
    0     0 DNAT       udp  --  any    any     anywhere             anywhere             /* kube-system/kube-dns:dns */ udp to:10.1.9.135:53
    0     0 KUBE-MARK-MASQ  all  --  any    any     10.1.44.135          anywhere             /* kube-system/kube-dns:dns */
    0     0 DNAT       udp  --  any    any     anywhere             anywhere             /* kube-system/kube-dns:dns */ udp to:10.1.44.135:53
    0     0 KUBE-MARK-MASQ  all  --  any    any     10.1.44.135          anywhere             /* kube-system/kube-dns:dns-tcp */
    0     0 DNAT       tcp  --  any    any     anywhere             anywhere             /* kube-system/kube-dns:dns-tcp */ tcp to:10.1.44.135:53
    0     0 KUBE-MARK-MASQ  all  --  any    any     10.1.2.131           anywhere             /* kube-system/kube-dns:dns-tcp */
    0     0 DNAT       tcp  --  any    any     anywhere             anywhere             /* kube-system/kube-dns:dns-tcp */ tcp to:10.1.2.131:53
    0     0 KUBE-MARK-MASQ  all  --  any    any     10.1.2.131           anywhere             /* kube-system/kube-dns:dns */
    0     0 DNAT       udp  --  any    any     anywhere             anywhere             /* kube-system/kube-dns:dns */ udp to:10.1.2.131:53
    0     0 KUBE-SVC-TCOU7JCQXEZGVUNU  udp  --  any    any     anywhere             10.0.220.2           /* kube-system/kube-dns:dns cluster IP */ udp dpt:domain
    0     0 KUBE-SVC-ERIFXISQEP7F7OF4  tcp  --  any    any     anywhere             10.0.220.2           /* kube-system/kube-dns:dns-tcp cluster IP */ tcp dpt:domain
    0     0 KUBE-SEP-R3MNZO3IZYST7DQN  all  --  any    any     anywhere             anywhere             /* kube-system/kube-dns:dns-tcp */ statistic mode random probability 0.33332999982
    0     0 KUBE-SEP-NDZPY3K7J7CU4723  all  --  any    any     anywhere             anywhere             /* kube-system/kube-dns:dns-tcp */ statistic mode random probability 0.50000000000
    0     0 KUBE-SEP-7NZGO3KR6PGGVEM3  all  --  any    any     anywhere             anywhere             /* kube-system/kube-dns:dns-tcp */
    0     0 KUBE-SEP-R5AV3ZTFSI6OUVLE  all  --  any    any     anywhere             anywhere             /* kube-system/kube-dns:dns */ statistic mode random probability 0.33332999982
    0     0 KUBE-SEP-J5TQCIJBNFAEPRA7  all  --  any    any     anywhere             anywhere             /* kube-system/kube-dns:dns */ statistic mode random probability 0.50000000000
    0     0 KUBE-SEP-D4OCUPRGMYJQ3M4N  all  --  any    any     anywhere             anywhere             /* kube-system/kube-dns:dns */

Then if I delete all 3 dns pods simultanously, all of the above entries are deleted except the two “KUBE-SVC…” entries pointing to the ClusterIP. It then takes a few seconds for new entries to appear relating to the new dns pods that were created.

If during these several seconds one of my nginx pods is trying to resolve its endpoint cluster ip, a new conntrack entry will be created for it looking like this:

# calling cat /proc/net/nf_conntrack | grep 'dport=53 \[UNREPLIED\] src=10.0.220.2' 
ipv4     2 udp      17 26 src=10.1.34.4 dst=10.0.220.2 sport=44999 dport=53 [UNREPLIED] src=10.0.220.2 dst=192.168.223.55 sport=53 dport=44999 mark=0 zone=0 use=2

It’s obviously using the only iptables entry that is relevant for it, which is pointing to the kube-dns ClusterIP, and this connection is not being replied… This conntrack entry has a ttl of 30s, and when running tcpdump on the k8s node I see that my nginx pod is now trying to send requests to this ip every 5 seconds so it will never be removed on its own (anyone has any idea where this 5s configuration is coming from?).

At this point my nginx pod gets stuck on the ‘Operation timed out’ resolver errors, and only some manual action like a conntrack flush or pod restart etc. will resolve the issue.

@dlouzan Thanks for the excellent investigation here! We’re running into this issue to running the latest stable openresty 1.11.2.2 which builds with nginx core 1.11.2. We’re on k8s 1.4.

I’d also like to clarify that, at least according to this article (https://www.nginx.com/blog/dns-service-discovery-nginx-plus/), the resolver configuration for nginx is only available in nginx 1.11.3+. I’m currently in the middle of testing a configuration using nginx upstream block configured with max_fails to brute force DNS resolution until it succeeds. In our case, the issue is intermittent and recovers in about a second.