[Dnsmasq-discuss] Still investigating delay on first dns query - more info

[Chris Green]

I'm still trying to work out why the first DNS query to dnsmasq
running on a server on my LAN suffers a 5 second delay but subsequent
requests don't see the delay.  

I'm running dnsmasq version 2.76 on a Raspberry Pi.  The systems
seeing the delay when they send a query are (mostly) running xubuntu
19.10.

The delay only occurs when querying names on the LAN, requests for
external names run normally.  It makes no difference whether I give a fully
qualified name or just the machine name (the domain gets added by the
'search' option in /etc/resolv.con anyway).

It appears to be something to do with IPV6 and AAAA records (or lack
of them) that causes the issue but I'm still stumped as to how to fix
it.  

Having set 'log-queries=extra' in /etc/dnsmasq.conf I see the
following in /var/log/syslog when I query (using 'host') the name
'esprimo' twice from my laptop after booting (booting the laptop that
is).

First 'host esprimo':-
    Mar 23 12:59:06 newdns dnsmasq[4256]: 54 192.168.1.92/56886 query[A] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 54 192.168.1.92/56886 /etc/hosts esprimo.zbmc.eu is 192.168.1.3
    Mar 23 12:59:06 newdns dnsmasq[4256]: 55 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 55 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 56 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 56 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 57 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 57 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 58 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 58 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 59 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 59 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 60 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 60 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 61 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 61 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 62 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 62 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 63 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 63 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 64 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 64 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 65 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 65 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 66 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 66 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 67 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 67 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 68 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 68 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 69 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 69 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 70 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 70 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 71 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 71 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 72 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 72 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 73 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 73 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 74 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 74 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 75 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 75 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 76 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 76 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 77 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 77 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:06 newdns dnsmasq[4256]: 78 192.168.1.92/37906 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:06 newdns dnsmasq[4256]: 78 192.168.1.92/37906 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:11 newdns dnsmasq[4256]: 79 192.168.1.92/35896 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:11 newdns dnsmasq[4256]: 79 192.168.1.92/35896 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:11 newdns dnsmasq[4256]: 80 192.168.1.92/48696 query[MX] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:11 newdns dnsmasq[4256]: 80 192.168.1.92/48696 config esprimo.zbmc.eu is NODATA


Second 'host esprimo':-
    Mar 23 12:59:25 newdns dnsmasq[4256]: 91 192.168.1.92/56179 query[A] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:25 newdns dnsmasq[4256]: 91 192.168.1.92/56179 /etc/hosts esprimo.zbmc.eu is 192.168.1.3
    Mar 23 12:59:25 newdns dnsmasq[4256]: 92 192.168.1.92/59553 query[AAAA] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:25 newdns dnsmasq[4256]: 92 192.168.1.92/59553 config esprimo.zbmc.eu is NODATA-IPv6
    Mar 23 12:59:25 newdns dnsmasq[4256]: 93 192.168.1.92/32976 query[MX] esprimo.zbmc.eu from 192.168.1.92
    Mar 23 12:59:25 newdns dnsmasq[4256]: 93 192.168.1.92/32976 config esprimo.zbmc.eu is NODATA


So for some reason first time round the querying system asks
repeatedly for the AAAA record, then waits 5 seconds, asks again and
then gives up.  But it only does this the first time it sends the
query.  (I suspect that the delay re-occurs after a long idle time but
I can't reproduce the delay by clearing the systemd resolvctl cache)

I realise this probably isn't directly a dnsmasq problem but I'd
really appreciate any suggestions or workarounds that might help me
fix this issue.  I can easily add more debug flags or configuration if
they might help.

-- 
Chris Green