Debug Cilium toFQDN network policies
Troubleshoot packet drops in Kong gateway when a hostname has CNAMEs attached
Little bit of background
We use Cilium as the CNI in our Azure AKS cluster. We run some Kong gateways as pods inside the cluster. Each gateway is allowed to talk to specific backends. This is done via cilium network policies. We use toFQDN based policies.
We noticed that some of the calls stuck at the pod/gateway and doesn’t reach the backend. It turned out that if a hostname resolves to some CNAMEs , then this behavior is seen. This blogpost explains the steps we followed during the troubleshooting/debugging and how we found the solution.
For this blog post I will use login.microsoftonline.com as it also resolves to lot of CNAMEs.
nslookup login.microsoftonline.com
Non-authoritative answer:
login.microsoftonline.com canonical name = login.mso.msidentity.com.
login.mso.msidentity.com canonical name = ak.privatelink.msidentity.com.
ak.privatelink.msidentity.com canonical name = www.tm.ak.prd.aadg.trafficmanager.net.
Name: www.tm.ak.prd.aadg.trafficmanager.net
Address: 20.190.151.134
Name: www.tm.ak.prd.aadg.trafficmanager.net
Address: 20.190.151.8
Name: www.tm.ak.prd.aadg.trafficmanager.net
Address: 20.190.151.131
Name: www.tm.ak.prd.aadg.trafficmanager.net
Address: 20.190.151.9
Name: www.tm.ak.prd.aadg.trafficmanager.net
Address: 20.190.151.133
Name: www.tm.ak.prd.aadg.trafficmanager.net
Address: 20.190.151.7
Name: www.tm.ak.prd.aadg.trafficmanager.net
Address: 20.190.151.70
Name: www.tm.ak.prd.aadg.trafficmanager.net
Address: 20.190.151.68
Exec into cilium pods
If you are troubleshooting some calls/requests related to a specific pod, then exec/ssh in to the cilium pod runs in the same worker node as your test pod.
k exec -it -n kube-system cilium-s8f8k -- /bin/bash
cilium-dbg CLI
This is a really nice tool where you can see whats in place with regard to network policies.
You may have toFQDNs, toEndpoints, or toCIDRSet. You can use cilium-dbg to check the details of these configs. We are using toFQDNs in the cilium network policy.
‘cilium-dbg fqdn names’ command will give you the polices along with regexes applied currently. These are the regexes evaluated by the cilium network policy against the requested upstream hostname, to decide wether to DROP or FORWARD .
~ cilium-dbg fqdn names
{
"DNSPollNames": null,
"FQDNPolicySelectors": [
{
"regexString": "^login[.]microsoftonline[.]com[.]$",
"selectorString": "MatchName: , MatchPattern: login.microsoftonline.com"
},
{
"regexString": "^httpbin[.]org[.]$",
"selectorString": "MatchName: , MatchPattern: httpbin.org"
}
]
}
You can see whats saved in the cache and you can clean the cache in case if you want.
cilium-dbg fqdn cache list
cilium-dbg fqdn cache clean
I cleaned the fqdn cached and called my api hosted in the Kong gateway. The upstream is set to login.microsoftonline.com. Hence now I should see what was added to the cache.
To my surprise I could see that instead of the parent hostname(login.microsoftonline.com) one of the CNAMEs has been added to the cache. Of course the requests to orignal hostname will not be allowed when the regex is evaluated against this table.
Now the question is why this happened, why only a cname was added to the whitelist cache.
This can be checked by observing hubble events.
hubble observe
Hubble observe cheat sheet has everything you need to know about this CLI
I sshed in to the cilium pod and observed hubble logs for the requests sent by my gateway to the coredns pods.
hubble observe --all -f | grep my-kong-gateway-pod-name | grep coredns
When observing the hubble events, I could notice that when Kong gateway sends the dns resolution request, it asks for CNAMEs. Hence the dns server responds with a CNAME. That is why it gets added to the cilium fqdn cache.
And if you do a curl command to the upstream within the Kong gateway, or even if you do a nslookup to this upstream host within the Kong gateway, you can see the dns requests are for A records. Hence dns server(coredns) responds with the parent hostname(A record)
For quick understanding about what A record means and what CNAME means, please have a look at this https://support.dnsimple.com/articles/differences-a-cname-records/
You can verify this behavior by looking at the core dns logs. There you can see all dns requests and responses.
Enable logs for coredns
You can add log plugin to the config map containing your coredns configurations. Depending on your deployment you can directly edit the coredns configmap or coredns-custom config map.
~ » kubectl get cm -n kube-system | grep coredns
coredns 1 91d
coredns-autoscaler 1 91d
coredns-custom 1 91d
--------------------------------------------------------------------------
~ » kg cm -n kube-system coredns-custom -oyaml
apiVersion: v1
data:
log.override: |
log
kind: ConfigMap
metadata:
labels:
addonmanager.kubernetes.io/mode: EnsureExists
k8s-app: kube-dns
kubernetes.io/cluster-service: "true"
name: coredns-custom
namespace: kube-system
Then you can tail logs of all coredns pods by using below command. If you filter by your gateway pod’s IP, then you can see all requests and responses related to that gateway pod.
Tail coredns pod logs
~ » k logs -f -l k8s-app=kube-dns -n kube-system | grep 172.16.128.101
>>>>>> API call to KONG GATEWAY >>>>>>>>>>
[INFO] 172.16.128.101:41746 - 11734 "CNAME IN login.microsoftonline.com.633c32ed-5272-4534-bb23-abe7d2ba25bb.svc.cluster.local. udp 98 false 512" NXDOMAIN qr,aa,rd 191 0.000244302s
[INFO] 172.16.128.101:45387 - 23534 "CNAME IN login.microsoftonline.com.svc.cluster.local. udp 61 false 512" NXDOMAIN qr,aa,rd 154 0.000278602s
[INFO] 172.16.128.101:37966 - 38300 "CNAME IN login.microsoftonline.com.cluster.local. udp 57 false 512" NXDOMAIN qr,aa,rd 150 0.000283903s
[INFO] 172.16.128.101:49063 - 51823 "CNAME IN ak.privatelink.msidentity.com.svc.cluster.local. udp 65 false 512" NXDOMAIN qr,aa,rd 158 0.000171602s
[INFO] 172.16.128.101:55530 - 56073 "CNAME IN login.mso.msidentity.com.633c32ed-5272-4534-bb23-abe7d2ba25bb.svc.cluster.local. udp 97 false 512" NXDOMAIN qr,aa,rd 190 0.000306903s
[INFO] 172.16.128.101:48229 - 60301 "CNAME IN ak.privatelink.msidentity.com.cluster.local. udp 61 false 512" NXDOMAIN qr,aa,rd 154 0.000222803s
[INFO] 172.16.128.101:60461 - 32090 "CNAME IN login.mso.msidentity.com.svc.cluster.local. udp 60 false 512" NXDOMAIN qr,aa,rd 153 0.000243302s
[INFO] 172.16.128.101:52358 - 598 "CNAME IN ak.privatelink.msidentity.com.633c32ed-5272-4534-bb23-abe7d2ba25bb.svc.cluster.local. udp 102 false 512" NXDOMAIN qr,aa,rd 195 0.000157302s
[INFO] 172.16.128.101:50880 - 31203 "CNAME IN login.mso.msidentity.com.cluster.local. udp 56 false 512" NXDOMAIN qr,aa,rd 149 0.000137001s
[INFO] 172.16.128.101:53513 - 35160 "A IN www.tm.ak.prd.aadg.trafficmanager.net. udp 55 false 512" NOERROR qr,rd,ra 479 0.002227116s
[INFO] 172.16.128.101:59443 - 63961 "CNAME IN login.mso.msidentity.com. udp 42 false 512" NOERROR qr,rd,ra 109 0.003439125s
>>>>>>>>>> nslookup to login.microsoftonline.com (from within gateway pod) >>>>>>>>>>>>>>>
[INFO] 172.16.128.101:43551 - 5915 "A IN login.microsoftonline.com.633c32ed-5272-4534-bb23-abe7d2ba25bb.svc.cluster.local. udp 98 false 512" NXDOMAIN qr,aa,rd 191 0.000191203s
[INFO] 172.16.128.101:39981 - 12670 "A IN login.microsoftonline.com.svc.cluster.local. udp 61 false 512" NXDOMAIN qr,aa,rd 154 0.000214402s
[INFO] 172.16.128.101:39357 - 4376 "A IN login.microsoftonline.com.cluster.local. udp 57 false 512" NXDOMAIN qr,aa,rd 150 0.000175702s
[INFO] 172.16.128.101:33449 - 2936 "A IN login.microsoftonline.com.o1ikz1dgopve1cyxujcpwlej2a.ax.internal.cloudapp.net. udp 95 false 512" NXDOMAIN qr,rd,ra 205 0.005404339s
[INFO] 172.16.128.101:37580 - 10065 "A IN login.microsoftonline.com. udp 43 false 512" NOERROR qr,rd,ra 677 0.003137037s
[INFO] 172.16.128.101:49021 - 61534 "AAAA IN www.tm.ak.prd.aadg.trafficmanager.net. udp 55 false 512" NOERROR qr,rd,ra 575 0.002312217s
>>>>>>>>>>>>>>> curl to login.microsoftonline.com (from within gateway pod) >>>>>>>>>>>>>>>>>>>>>>>>
[INFO] 172.16.128.101:33892 - 27891 "A IN login.microsoftonline.com.633c32ed-5272-4534-bb23-abe7d2ba25bb.svc.cluster.local. udp 98 false 512" NXDOMAIN qr,aa,rd 191 0.000262603s
[INFO] 172.16.128.101:33892 - 1410 "AAAA IN login.microsoftonline.com.633c32ed-5272-4534-bb23-abe7d2ba25bb.svc.cluster.local. udp 98 false 512" NXDOMAIN qr,aa,rd 191 0.000361504s
[INFO] 172.16.128.101:54491 - 13916 "A IN login.microsoftonline.com.svc.cluster.local. udp 61 false 512" NXDOMAIN qr,aa,rd 154 0.000221902s
[INFO] 172.16.128.101:54491 - 31715 "AAAA IN login.microsoftonline.com.svc.cluster.local. udp 61 false 512" NXDOMAIN qr,aa,rd 154 0.000277402s
[INFO] 172.16.128.101:57083 - 42807 "A IN login.microsoftonline.com.cluster.local. udp 57 false 512" NXDOMAIN qr,aa,rd 150 0.000205401s
[INFO] 172.16.128.101:57083 - 38929 "AAAA IN login.microsoftonline.com.cluster.local. udp 57 false 512" NXDOMAIN qr,aa,rd 150 0.000268702s
[INFO] 172.16.128.101:42262 - 52455 "A IN login.microsoftonline.com.o1ikz1dgopve1cyxujcpwlej2a.ax.internal.cloudapp.net. udp 95 false 512" NXDOMAIN qr,rd,ra 205 0.003068836s
[INFO] 172.16.128.101:42262 - 62101 "AAAA IN login.microsoftonline.com.o1ikz1dgopve1cyxujcpwlej2a.ax.internal.cloudapp.net. udp 95 false 512" NXDOMAIN qr,rd,ra 205 0.003563242s
[INFO] 172.16.128.101:44814 - 41917 "AAAA IN login.microsoftonline.com. udp 43 false 512" NOERROR qr,rd,ra 701 0.003104936s
[INFO] 172.16.128.101:44814 - 36443 "A IN login.microsoftonline.com. udp 43 false 512" NOERROR qr,rd,ra 605 0.003264339s
Now the question is why this happens ONLY when Kong gateway tries to resolve the dns for its api calls, WHY Kong gateway asks for CNAMEs first instead of A records.
*DNS queries are done as per the configurations in /etc/resolve.conf file in the gateway pod.
Kong DNS Order
Kong gateway has a way to define the kong dns resolution oder. The order in which to resolve different record types.
Override the default value and change as below would make the Kong gateway also to request for A records first from the dns server. Which resolved our issue.
env:
- name: KONG_DNS_ORDER
value: A,CNAME,LAST,SRV
Now I could see even for my API call also, Kong gateway asks for A records first, hence dns server(coredns) responds with A record. Therefore that gets added in to the fqdn cache. Because of that, whitelisting works and requests are allowed to the parent hostname. And you dont need to add each and every CNAME to your cilium network policy. Adding the parent hostname would be enough to allow traffic.
DNS server logs
k logs -f -l k8s-app=kube-dns -n kube-system | grep <pod-ip>
[INFO] 172.16.128.10:41406 - 64652 "A IN ak.privatelink.msidentity.com.svc.cluster.local. udp 65 false 512" NXDOMAIN qr,aa,rd 158 0.000156201s
[INFO] 172.16.128.10:42626 - 61330 "A IN ak.privatelink.msidentity.com.cluster.local. udp 61 false 512" NXDOMAIN qr,aa,rd 154 0.000146601s
[INFO] 172.16.128.10:44486 - 61101 "A IN ak.privatelink.msidentity.com. udp 47 false 512" NOERROR qr,rd,ra 479 0.00268662s
[INFO] 172.16.128.10:58032 - 17372 "A IN ak.privatelink.msidentity.com.633c32ed-5272-4534-bb23-abe7d2ba25bb.svc.cluster.local. udp 102 false 512" NXDOMAIN qr,aa,rd 195 0.000131301s
[INFO] 172.16.128.10:35018 - 29907 "A IN ak.privatelink.msidentity.com.o1ikz1dgopve1cyxujcpwlej2a.ax.internal.cloudapp.net. udp 99 false 512" NXDOMAIN qr,rd,ra 209 0.004849356s
[INFO] 172.16.128.10:44051 - 17030 "CNAME IN ak.privatelink.msidentity.com.633c32ed-5272-4534-bb23-abe7d2ba25bb.svc.cluster.local. udp 102 false 512" NXDOMAIN qr,aa,rd 195 0.000166701s
[INFO] 172.16.128.10:44446 - 6120 "CNAME IN ak.privatelink.msidentity.com.svc.cluster.local. udp 65 false 512" NXDOMAIN qr,aa,rd 158 0.000163201s
[INFO] 172.16.128.10:38258 - 60283 "CNAME IN ak.privatelink.msidentity.com.cluster.local. udp 61 false 512" NXDOMAIN qr,aa,rd 154 0.000151401s
[INFO] 172.16.128.10:42362 - 65318 "CNAME IN ak.privatelink.msidentity.com.o1ikz1dgopve1cyxujcpwlej2a.ax.internal.cloudapp.net. udp 99 false 512" NXDOMAIN qr,rd,ra 209 0.00511496s
~:/home/cilium# cilium-dbg fqdn cache list
Endpoint Source FQDN TTL ExpirationTime IPs
2811 lookup login.mso.msidentity.com. 14 2024-10-16T10:28:45.599Z 20.190.160.14,40.126.32.76,20.190.160.20,40.126.32.74,40.126.32.138,20.190.160.22,40.126.32.133,40.126.32.134
2811 lookup ak.privatelink.msidentity.com. 30 2024-10-16T10:29:01.600Z 20.190.159.0,20.190.159.2,40.126.31.73,20.190.159.4,20.190.159.68,40.126.31.67,20.190.159.23,20.190.159.73
2811 lookup login.microsoftonline.com. 15 2024-10-16T10:28:46.597Z 40.126.32.136,40.126.32.74,40.126.32.68,40.126.32.133,40.126.32.72,40.126.32.134,20.190.160.22,20.190.160.20
2811 lookup www.tm.ak.prd.aadg.akadns.net. 30 2024-10-16T10:29:01.599Z 40.126.32.76,40.126.32.133,20.190.160.17,40.126.32.134,40.126.32.138,20.190.160.22,40.126.32.136,40.126.32.74
Thats it folks!! Cheers!!! :)