0

I have a small home LAN with dnsmasq running on a Raspberry Pi to provide DHCP and DNS services. I have two systems running xubuntu 19.10 and on these systems I see a 5 second delay the first time I look up the address of a local host. Subsequent lookups are fast but if the system is idle for a long time (I haven't quite fathomed out how long) I see the 5 second delay again.

The delay can be changed by setting the timeout option in /etc/resolv.conf.

I have seen others with similar problems but adding the single-request-reopen or single-request options to /etc/resolv.conf doesn't help on my systems.

I have run tcpdump on one of the clients and what it shows is very odd, the first/slow lookup shows:-

15:06:46.494698 IP 192.168.1.109.47247 > 192.168.1.4.53: 17387+ [1au] A? esprimo.zbmc.eu. (44)
15:06:46.495458 IP 192.168.1.4.53 > 192.168.1.109.47247: 17387* 1/0/1 A 192.168.1.3 (60)
15:06:46.497254 IP 192.168.1.109.47346 > 192.168.1.4.53: 30260+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.497823 IP 192.168.1.4.53 > 192.168.1.109.47346: 30260 0/0/0 (33)
15:06:46.497905 IP 192.168.1.109.47346 > 192.168.1.4.53: 51192+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.498386 IP 192.168.1.4.53 > 192.168.1.109.47346: 51192 0/0/0 (33)
15:06:46.498452 IP 192.168.1.109.47346 > 192.168.1.4.53: 33447+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.498938 IP 192.168.1.4.53 > 192.168.1.109.47346: 33447 0/0/0 (33)
15:06:46.499005 IP 192.168.1.109.47346 > 192.168.1.4.53: 22508+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.499479 IP 192.168.1.4.53 > 192.168.1.109.47346: 22508 0/0/0 (33)
15:06:46.499543 IP 192.168.1.109.47346 > 192.168.1.4.53: 29909+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.500002 IP 192.168.1.4.53 > 192.168.1.109.47346: 29909 0/0/0 (33)
15:06:46.500065 IP 192.168.1.109.47346 > 192.168.1.4.53: 30282+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.500514 IP 192.168.1.4.53 > 192.168.1.109.47346: 30282 0/0/0 (33)
15:06:46.500577 IP 192.168.1.109.47346 > 192.168.1.4.53: 61787+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.501035 IP 192.168.1.4.53 > 192.168.1.109.47346: 61787 0/0/0 (33)
15:06:46.501098 IP 192.168.1.109.47346 > 192.168.1.4.53: 54396+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.501542 IP 192.168.1.4.53 > 192.168.1.109.47346: 54396 0/0/0 (33)
15:06:46.501604 IP 192.168.1.109.47346 > 192.168.1.4.53: 23954+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.502065 IP 192.168.1.4.53 > 192.168.1.109.47346: 23954 0/0/0 (33)
15:06:46.502129 IP 192.168.1.109.47346 > 192.168.1.4.53: 54304+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.502593 IP 192.168.1.4.53 > 192.168.1.109.47346: 54304 0/0/0 (33)
15:06:46.502658 IP 192.168.1.109.47346 > 192.168.1.4.53: 45756+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.503237 IP 192.168.1.4.53 > 192.168.1.109.47346: 45756 0/0/0 (33)
15:06:46.503301 IP 192.168.1.109.47346 > 192.168.1.4.53: 41800+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.503765 IP 192.168.1.4.53 > 192.168.1.109.47346: 41800 0/0/0 (33)
15:06:46.503829 IP 192.168.1.109.47346 > 192.168.1.4.53: 31311+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.504287 IP 192.168.1.4.53 > 192.168.1.109.47346: 31311 0/0/0 (33)
15:06:46.504350 IP 192.168.1.109.47346 > 192.168.1.4.53: 6714+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.504791 IP 192.168.1.4.53 > 192.168.1.109.47346: 6714 0/0/0 (33)
15:06:46.504853 IP 192.168.1.109.47346 > 192.168.1.4.53: 62324+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.505318 IP 192.168.1.4.53 > 192.168.1.109.47346: 62324 0/0/0 (33)
15:06:46.505381 IP 192.168.1.109.47346 > 192.168.1.4.53: 32434+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.505831 IP 192.168.1.4.53 > 192.168.1.109.47346: 32434 0/0/0 (33)
15:06:46.505894 IP 192.168.1.109.47346 > 192.168.1.4.53: 7912+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.506350 IP 192.168.1.4.53 > 192.168.1.109.47346: 7912 0/0/0 (33)
15:06:46.506413 IP 192.168.1.109.47346 > 192.168.1.4.53: 4391+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.506860 IP 192.168.1.4.53 > 192.168.1.109.47346: 4391 0/0/0 (33)
15:06:46.506924 IP 192.168.1.109.47346 > 192.168.1.4.53: 33948+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.507372 IP 192.168.1.4.53 > 192.168.1.109.47346: 33948 0/0/0 (33)
15:06:46.507435 IP 192.168.1.109.47346 > 192.168.1.4.53: 31485+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.507879 IP 192.168.1.4.53 > 192.168.1.109.47346: 31485 0/0/0 (33)
15:06:46.507942 IP 192.168.1.109.47346 > 192.168.1.4.53: 54625+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.508388 IP 192.168.1.4.53 > 192.168.1.109.47346: 54625 0/0/0 (33)
15:06:46.508451 IP 192.168.1.109.47346 > 192.168.1.4.53: 10602+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.508911 IP 192.168.1.4.53 > 192.168.1.109.47346: 10602 0/0/0 (33)
15:06:46.508973 IP 192.168.1.109.47346 > 192.168.1.4.53: 49099+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.509418 IP 192.168.1.4.53 > 192.168.1.109.47346: 49099 0/0/0 (33)
15:06:46.509480 IP 192.168.1.109.47346 > 192.168.1.4.53: 29655+ [1au] AAAA? esprimo.zbmc.eu. (44)
15:06:46.509937 IP 192.168.1.4.53 > 192.168.1.109.47346: 29655 0/0/0 (33)
15:06:56.498320 IP 192.168.1.109.41148 > 192.168.1.4.53: 17631+ AAAA? esprimo.zbmc.eu. (33)
15:06:56.499140 IP 192.168.1.4.53 > 192.168.1.109.41148: 17631 0/0/0 (33)
15:06:56.500756 IP 192.168.1.109.60324 > 192.168.1.4.53: 52387+ MX? esprimo.zbmc.eu. (33)
15:06:56.501332 IP 192.168.1.4.53 > 192.168.1.109.60324: 52387 0/0/0 (33)

A good/fast lookup shows:-

15:08:15.912561 IP 192.168.1.109.59396 > 192.168.1.4.53: 10912+ A? esprimo.zbmc.eu. (33)
15:08:15.913258 IP 192.168.1.4.53 > 192.168.1.109.59396: 10912* 1/0/0 A 192.168.1.3 (49)
15:08:15.913697 IP 192.168.1.109.50463 > 192.168.1.4.53: 35415+ AAAA? esprimo.zbmc.eu. (33)
15:08:15.914255 IP 192.168.1.4.53 > 192.168.1.109.50463: 35415 0/0/0 (33)
15:08:15.914718 IP 192.168.1.109.44070 > 192.168.1.4.53: 32499+ MX? esprimo.zbmc.eu. (33)
15:08:15.915186 IP 192.168.1.4.53 > 192.168.1.109.44070: 32499 0/0/0 (33)

So what is happening here? It looks as if the client system goes crazy and asks for the AAAA record repeatedly, then gives up for the time out period (set by /etc/resolv.conf to 10 seconds at the moment), then asks the same again and understands the answer.

It does definitely seem to be a client issue as I have other systems which don't seem to behave like this.

  • 1
    You're doing a tcpdump capture to debug DNS, while leaving tcpdump's DNS resolution ON, leading to additional DNS requests. You should run the same capture with tcpdump -n to turn off DNS. This would help get a clearer picture of the actual issue. – A.B Mar 27 at 20:13
  • also at random, see if this might be related: git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/… . Afaik It would happen with nat/conntrack when a DNS request for both A and AAAA records happen very fast in parallel using the same UDP source port. The fix in the patch has not yet reached a stable kernel (will be in 5.6+ and might perhaps be backported). – A.B Mar 27 at 20:27
  • I've tried using 'tcpdump -n ...' and the results look identical to me, except for numeric IP addreses of course. I can't post the results as a comment because they're too long. As a further note I'm pretty certain that an ubuntu 18.04 system doesn't show the problem. – Chris Green Mar 28 at 15:15
  • 1
    you can edit your question if needed. Anyway I wouldn't know how to help more myself. – A.B Mar 28 at 15:16
  • So I can (edit my question that is), thanks, done. – Chris Green Mar 28 at 15:46

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.