Pdns: login.citrixonline.com sometimes returns SERVFAIL

[mzealey]

We have an intermittent issue on our resolvers in 4.0.3 whereby a lookup of login.citrixonline.com sometimes returns SERVFAIL and continues to do this until we restart the recursor. We cannot reproduce in a lab but see this every few days due to our live traffic. (note: we are nothing to do with citrix this is outside of their network)

I am not sure if this is related, but we have had this problem reported to us only after we set edns-subnet-whitelist=0.0.0.0/0 in the config (and it appears that the upstream servers have this enabled as we have seen different IPs based on our source IP address). The next step if these traces are not good enough is to revert this and see if the issue still occurs.

I have attached 3 traces:

• trace-normal.txt shows what happens when a typical lookup occurs. This is when the glue records (ns3.citrixonlinecdn.com) are found in the cache.
• trace-last-good.txt shows the last good query before the issue occurs. It appears in this one that the glue records were not found in the cache and so it went to the com servers to look them up.
• trace-first-failure.txt shows the (very long) trace process occuring when the failure first happens and I believe subsequent queries do this. For some reason I don't understand it seems to be rejecting the glue records that it receives from the .com servers, looping a number of times before finally giving up and issuing a SERVFAIL. The key part here seems to be:

Sep 21 21:39:33 pdns_recursor:  [3175694]    ns3.citrixonlinecdn.com: accept answer 'ns3.citrixonlinecdn.com|A|67.217.67.203' from 'com' nameservers? 3 YES!
Sep 21 21:39:33 pdns_recursor:  [3175694]    ns3.citrixonlinecdn.com: accept answer 'ns4.citrixonlinecdn.com|A|216.219.116.194' from 'com' nameservers? 3 YES!
Sep 21 21:39:33 pdns_recursor:  [3175694]    ns3.citrixonlinecdn.com: OPT answer '.' from 'com' nameservers
Sep 21 21:39:33 pdns_recursor:  [3175694]    ns3.citrixonlinecdn.com: determining status after receiving this packet
Sep 21 21:39:33 pdns_recursor:  [3175694]    ns3.citrixonlinecdn.com: got NS record 'citrixonlinecdn.com' -> 'ns3.citrixonlinecdn.com.'
Sep 21 21:39:33 pdns_recursor:  [3175694]    ns3.citrixonlinecdn.com: got NS record 'citrixonlinecdn.com' -> 'ns4.citrixonlinecdn.com.'
Sep 21 21:39:33 pdns_recursor:  [3175694]    ns3.citrixonlinecdn.com: status=did not resolve, got 2 NS, looping to them
Sep 21 21:39:33 pdns_recursor:  [3175694]    ns3.citrixonlinecdn.com.: Nameservers: ns3.citrixonlinecdn.com.(1.85ms), ns4.citrixonlinecdn.com.(42.17ms)
Sep 21 21:39:33 pdns_recursor:  [3175694]    ns3.citrixonlinecdn.com: Not using NS to resolve itself! (1/2)
Sep 21 21:39:33 pdns_recursor:  [3175694]    ns3.citrixonlinecdn.com: Trying to resolve NS 'ns4.citrixonlinecdn.com' (2/2)

I also attach pdns-cache-citrix.txt which is the output of rec_control dump-cache | grep citrix at the time of the issue.

[mzealey]

It appears that ns*.citrixonlinecdn.com nameservers don't support edns - they return a FORMERR when you dig +subnet=123.10.9.0/24 @ns4.citrixonlinecdn.com ns4.citrixonlinecdn.com. In this case, according to the comment in SyncRes::asyncresolveWrapper it should drop back to a bare dns query. The resolver seems to be doing this usually as TTL on the login. record is only 60 sec so it will continually be being queried. So as far as I can see up to a certain point resolution is working correctly, but then for some reason something changes and it can no longer resolve against these nameservers.

[mzealey]

citrix.pcap.gz is the output of

tcpdump -n -s0 -r out.pcap -w citrix.pcap 'host ns3.citrixonlinecdn.com or host ns4.citrixonlinecdn.com or host ns-c.pnap.net or host ns-a.pnap.net. or host ns-b.pnap.net. or host ns-d.pnap.net. or host ns1.citrixonline.com or host ns2.citrixonline.com or host ns3.citrixonline.com'

Our servers have a resolver -> recursor (ie external-facing) and a recursor -> auth server (ie general interenet facing) interface so you won't see the inbound questions but this should be all traffic from recursor -> auth servers.

The last good query response was at 51:33, which also seems to be the last time ns3/4.*cdn.com were contacted by pdns. There were a number of queries following that failed until we stopped the capture ~6 min later.

[mzealey]

I have the trace from these too by the way but i think they are just the same as the ones i shared before.

[mzealey]

I'm pretty confident this is a result of edns-subnet - since disabling it last week we have not seen this issue again.

[mzealey]

We confirm this is a bug caused by edns-subnet being enabled.

[mzealey]

Hi there, just wondering if there has been any work done on this ?

[Habbie]

No work has been done on this. Maybe we need an edns-subnet-blacklist? I'm assuming you're running with edns-subnet-whitelist=0.0.0.0/0 or the like?

[mzealey]

That's correct, although it looks to me more like a pdns bug than a remote server one as it works most of the time even with edns subnet enabled, and works all of the time with edns subnet disabled therefore I'm not sure which DNS servers we should blacklist. Also iirc we had it happen potentially on a different domain but I can't find details of this now.

[MikeSchroll]

I'm seeing the same behavior: If there is a fallback to a non edns client subnet request; it is not working as intended.

And it appears I have no other fallback options to stop pdns-recursor from sending ECS with its queries while configured for edns-subnet-whitelist=0.0.0.0/0.

What I expected is that 'use-incoming-edns-subnet=yes' could allow for no ECS to be sent if I did not pass it along; but it seems the behavior is:
edns-subnet-whitelist - if request comes from an IP in this range; ALWAYS send on ECS info to the authoritative server. By default generate and provide the connecting IP as ECS.
While that option is enabled, you can optionally replace ECS of the requesting IP for that specified in the eDNS area.

There's reference here: https://github.com/PowerDNS/pdns/issues/3262#issuecomment-173637427 to a ECS subnet of 0 telling the recursor to not pass edns info -- but I was unable to get this to work as expected.

[Habbie]

edns-subnet-whitelist - if request comes from an IP in this range; ALWAYS send on ECS info to the authoritative server.

the whitelist lists IPs to send ECS -to-. It's best to configure this to a known good set of auths that can deal with ECS.

[Habbie]

There's reference here: #3262 (comment) to a ECS subnet of 0 telling the recursor to not pass edns info -- but I was unable to get this to work as expected.

If that does not work, please file a separate ticket about this!

[zeha]

Recent versions can take exclusions in netmask lists, so 0.0.0.0/0 !192.0.2.0/24 is now a valid whitelist.

There's reference here: #3262 (comment) to a ECS subnet of 0 telling the recursor to not pass edns info -- but I was unable to get this to work as expected.

This may be improved by #5993.

[clokep]

This exact example seems to work fine now. Testing using @mzealey's steps above: dig +subnet=123.10.9.0/24 @ns4.citrixonlinecdn.com ns4.citrixonlinecdn.com yields a proper response.

I believe we can close this due to:

1. The server seems to be fixed.
2. Additional features in newer versions of PowerDNS allow for more fine-grained control here.
3. (I think that) 2019 DNS flag day means that the behavior of this authoritative server would now be considered invalid anyway.

[mzealey]

We got a similar issue again. Here is a note of the issue & why it's a wontfix:

$ dig @74.112.121.148 citrix.sw21cloud.com A 
; <<>> DiG 9.16.1-Ubuntu <<>> @74.112.121.148 citrix.sw21cloud.com A
; (1 server found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: FORMERR, id: 35167
;; flags: qr rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1
;; WARNING: recursion requested but not available
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 4096
; COOKIE: 8144a7717f8cf6a9 (echoed)
;; QUESTION SECTION:
;citrix.sw21cloud.com.          IN      A
;; Query time: 88 msec
;; SERVER: 74.112.121.148#53(74.112.121.148)
;; WHEN: Fri Oct 23 10:46:51 BST 2020
;; MSG SIZE  rcvd: 61

But with +noedns it works just fine.

(10:55:36) Habbie: jalh, so they are not saying 'we do not do EDNS'
(10:55:48) Habbie: jalh, they are saying 'we do EDNS and the options in your question are malformed'
(10:56:12) jalh: ya i see the 'EDNS: version: 0, flags:; udp: 4096' in the response from that ip
(10:56:13) Habbie: jalh, there is no way for us to recover from that
(10:56:39) Habbie: jalh, yes sorry, just that, not even the mirroring of the options, is the problem
(10:57:08) Habbie: if an auth replies EDNS+FORMERR, everything ends
(10:57:11) jalh: if it supports edns but returns a FORMERR could we work around to try without edns?
(10:57:28) Habbie: hmm?
(10:57:33) Habbie: but it doesn't support edns
(10:57:43) jalh: ok 'claims to support edns' then ?
(10:57:59) Habbie: no

(10:56:21) Habbie: jalh, and nobody should be running with edns-subnet for 0/0
(10:59:17) jalh: why do you say "nobody should be running with edns-subnet for 0/0" ?
(10:59:28) Habbie: because there are lots of broken auths out there
(10:59:52) Habbie: also edns subnet is terrible for your cache hit ratio on domains that do support it
(11:00:01) Habbie: and many that do support it, you don't actually need it for
(11:00:30) jalh: fair enough. for the resolver i'm currently working on it would be nice to be able to forward geoip stuff through in general. but i agree it's not absolutely necessary
(11:00:44) Habbie: the few places you really want it, like akamai
(11:00:51) Habbie: they'll ignore your ECS until you sign a contract anyway