[systemd-devel] systemd-resolved continuously switching DNS servers

[Kai Krakow]

Am Sat, 6 May 2017 14:22:21 +0200
schrieb Kai Krakow <hurikhan77 at gmail.com>:

> Am Fri, 5 May 2017 20:18:41 +0200
> schrieb Lennart Poettering <lennart at poettering.net>:
> 
> > On Fri, 05.05.17 01:01, Kai Krakow (hurikhan77 at gmail.com) wrote:
> >   
> > > Hello!
> > > 
> > > Why is systemd-resolved switching DNS servers all day long? This
> > > doesn't seem to be right...    
> > 
> > If you turn on debug logging, you should see an explanation right
> > before each switch. I figure we should choose the log levels more
> > carefully, so that whenever we switch we also log the reason at the
> > same level...  
> 
> It looks like this all has to do with timeouts:

Fixed by restarting the router. The cable modem seems to be buggy with
UDP packets after a lot of uptime: it simply silently drops UDP
packets at regular intervals, WebUI was also very slow, probably a CPU
issue.

I'll follow up on this with the cable provider.

When the problem starts to show up, systemd-resolved is affected more
by this than direct resolving. I don't know if there's something that
could be optimized in systemd-resolved to handle such issues better but
I don't consider it a bug in systemd-resolved, it was a local problem.

Thanks,
Kai

 
> Mai 06 14:17:09 jupiter systemd-resolved[5585]: Cache miss for
> ssl.gstatic.com IN AAAA Mai 06 14:17:09 jupiter
> systemd-resolved[5585]: Transaction 54375 for <ssl.gstatic.com IN
> AAAA> scope dns on enp5s0/*. Mai 06 14:17:09 jupiter
> AAAA> systemd-resolved[5585]: Using feature level UDP for transaction
> AAAA> 54375. Mai 06 14:17:09 jupiter systemd-resolved[5585]: Using
> AAAA> DNS server fe80::b248:7aff:fee7:f438%2 for transaction 54375.
> Mai 06 14:17:09 jupiter systemd-resolved[5585]: Sending query packet
> with id 54375. Mai 06 14:17:09 jupiter systemd-resolved[5585]:
> Timeout reached on transaction 33004. Mai 06 14:17:09 jupiter
> systemd-resolved[5585]: Retrying transaction 33004. Mai 06 14:17:09
> jupiter systemd-resolved[5585]: Switching to DNS server
> 2a02:8109:1ec0:6f5:5667:51ff:feea:385f for interface enp5s0. Mai 06
> 14:17:09 jupiter systemd-resolved[5585]: Cache miss for
> ssl.gstatic.com IN A Mai 06 14:17:09 jupiter systemd-resolved[5585]:
> Transaction 33004 for <ssl.gstatic.com IN A> scope dns on enp5s0/*.
> Mai 06 14:17:09 jupiter systemd-resolved[5585]: Using feature level
> UDP for transaction 33004. Mai 06 14:17:09 jupiter
> systemd-resolved[5585]: Using DNS server
> 2a02:8109:1ec0:6f5:5667:51ff:feea:385f for transaction 33004. Mai 06
> 14:17:09 jupiter systemd-resolved[5585]: Sending query packet with id
> 33004. Mai 06 14:17:09 jupiter systemd-resolved[5585]: Processing
> incoming packet on transaction 33004. (rcode=SUCCESS) Mai 06 14:17:09
> jupiter systemd-resolved[5585]: Not validating response for 33004,
> used server feature level does not support DNSSEC. Mai 06 14:17:09
> jupiter systemd-resolved[5585]: Added positive unauthenticated cache
> entry for ssl.gstatic.com IN A 143s on
> */INET6/2a02:8109:1ec0:6f5:5667:51ff:feea:385f Mai 06 14:17:09
> jupiter systemd-resolved[5585]: Transaction 33004 for
> <ssl.gstatic.com IN A> on scope dns on enp5s0/* now complete with
> <success> from network (unsigned). Mai 06 14:17:09 jupiter
> systemd-resolved[5585]: Sending response packet with id 42127 on
> interface 1/AF_INET. Mai 06 14:17:09 jupiter systemd-resolved[5585]:
> Sending response packet with id 22131 on interface 1/AF_INET. Mai 06
> 14:17:09 jupiter systemd-resolved[5585]: Processing incoming packet
> on transaction 54375. (rcode=SUCCESS) Mai 06 14:17:09 jupiter
> systemd-resolved[5585]: Not validating response for 54375, used
> server feature level does not support DNSSEC. Mai 06 14:17:09 jupiter
> systemd-resolved[5585]: Added positive unauthenticated cache entry
> for ssl.gstatic.com IN AAAA 203s on
> enp5s0/INET6/fe80::b248:7aff:fee7:f438 Mai 06 14:17:09 jupiter
> systemd-resolved[5585]: Transaction 54375 for <ssl.gstatic.com IN
> AAAA> on scope dns on enp5s0/* now complete with <success> from
> AAAA> network (unsigned). Mai 06 14:17:09 jupiter
> AAAA> systemd-resolved[5585]: Freeing transaction 33004. Mai 06
> AAAA> 14:17:09 jupiter systemd-resolved[5585]: Sent message
> AAAA> type=method_return sender=n/a destination=:1.352 object=n/a
> AAAA> interface=n/a member=n/a cookie=234 reply_cookie=2 error=n/a
> AAAA> Mai 06 14:17:09 jupiter systemd-resolved[5585]: Sent message
> AAAA> type=method_call sender=n/a destination=org.freedesktop.DBus
> AAAA> object=/org/freedesktop/DBus interface=org.freedesktop.DBus
> AAAA> member=RemoveMatch cookie=235 reply_cookie=0 erro Mai 06
> AAAA> 14:17:09 jupiter systemd-resolved[5585]: Got message
> AAAA> type=method_return sender=org.freedesktop.DBus
> AAAA> destination=:1.273 object=n/a interface=n/a member=n/a
> AAAA> cookie=181 reply_cookie=235 error=n/a Mai 06 14:17:09 jupiter
> AAAA> systemd-resolved[5585]: Freeing transaction 54375.
> 
> I just don't unterstand why, because all these nameservers work
> perfectly well when used directly and not through the stub resolver.


-- 
Regards,
Kai

Replies to list-only preferred.