[Networkmanager] dns-mgr occasionally writes resolv.conf in the wrong order

Sat Jun 24 13:30:32 UTC 2023

Sometimes I end up with a resolv.conf in the wrong order wrt routing
defaults.  The DNS servers listed first do not belong to the ISP
providing the default route.

This causes severe DNS timeout isues because those servers either are
unreachable or refuse recursive queries over the default route.

I believe the problem started when I went from the Debian bullseye to
the Debian bookwork version of NetworkManager. I.e from 1.30.6 to
1.42.4, but with some Debian patches if relevant.  I've been trying to
reproduce it for a while, without being able to force it.  So I'm not
exactly sure what the trigger is.

Anyway, it just happened again:

root at miraculix:/tmp# cat /etc/resolv.conf
# Generated by NetworkManager
search mork.no ti.telenor.net
nameserver 193.213.112.4
nameserver 130.67.15.198
nameserver 2001:4600:4:fff::52
# NOTE: the libc resolver may not support more than 3 nameservers.
# The nameservers listed below may not be recognized.
nameserver 2001:4600:4:1fff::52
nameserver 109.247.114.4
nameserver 92.220.228.70
nameserver 2a01:798:0:8012::4
nameserver 2a01:798:0:9002::70

The 4 first servers here (2 x IPv4 + 2 x IPv6) all belong to the wwan0
link.  The 4 next servers belong to the wlan0 link.

But all 8 servers will be routed over the wlan0 link, making the first 4
fail:

root at miraculix:/tmp# ip route
default via 192.168.10.1 dev wlan0 proto dhcp src 192.168.10.214 metric 600 
default via 10.49.202.41 dev wwan0 proto static metric 700 
10.49.202.40/30 dev wwan0 proto kernel scope link src 10.49.202.42 metric 700 
172.17.0.0/16 dev docker0 proto kernel scope link src 172.17.0.1 linkdown 
192.168.10.0/24 dev wlan0 proto kernel scope link src 192.168.10.214 metric 600 

root at miraculix:/tmp# ip -6 route
::1 dev lo proto kernel metric 256 pref medium
2a01:799:964:4b0a::/64 dev wlan0 proto ra metric 600 pref medium
2a02:2121:6b5:c77e::/64 dev wwan0 proto kernel metric 700 pref medium
fe80::/64 dev docker0 proto kernel metric 256 linkdown pref medium
fe80::/64 dev wlan0 proto kernel metric 1024 pref medium
default via fe80::dea6:32ff:fe77:e55e dev wlan0 proto ra metric 600 pref medium
default via 2a02:2121:6b5:c77e:25d2:5b6f:4811:98d1 dev wwan0 proto static metric 700 pref medium

With ifindexes for the log reference below:

root at miraculix:/tmp# ip link
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN mode DEFAULT group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
2: eth0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc fq_codel state DOWN mode DEFAULT group default qlen 1000
    link/ether 54:ee:75:9a:bf:58 brd ff:ff:ff:ff:ff:ff
3: wlan0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP mode DORMANT group default qlen 1000
    link/ether 44:85:00:11:26:e6 brd ff:ff:ff:ff:ff:ff
23: docker0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue state DOWN mode DEFAULT group default 
    link/ether 02:42:08:be:5f:65 brd ff:ff:ff:ff:ff:ff
29: wwan0: <BROADCAST,MULTICAST,NOARP,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UNKNOWN mode DEFAULT group default qlen 1000
    link/ether fa:1d:b6:3f:87:83 brd ff:ff:ff:ff:ff:ff

This is a part of the NetworkManager log with DNS logging level set to TRACE:

Jun 24 14:37:55 miraculix NetworkManager[1565954]: <debug> [1687610275.5001] dns-mgr: (device_l3cd_changed): queueing DNS updates (1)
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5002] policy: set-hostname: updating hostname (ip conf)
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5003] policy: get-hostname: "miraculix"
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5003] policy: get-hostname: "miraculix"
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5003] policy: set-hostname: hostname already set to 'miraculix' (from system configuration)
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <debug> [1687610275.5003] dns-mgr: (device_l3cd_changed): DNS configuration changed
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <debug> [1687610275.5003] dns-mgr: (device_l3cd_changed): committing DNS changes (0)
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <debug> [1687610275.5003] dns-mgr: update-dns: updating resolv.conf
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5004] dns-mgr: config:      100 best    v4 29    : 193.213.112.4 130.67.15.198
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5004] dns-mgr: config:      100 best    v6 29    : 2001:4600:4:fff::52 2001:4600:4:1fff::52
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5004] dns-mgr: config:      100 best    v4 3     : 109.247.114.4 92.220.228.70
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5004] dns-mgr: config:      100 best    v6 3     : 2a01:798:0:8012::4 2a01:798:0:9002::70
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5004] dns-mgr: plugin: add domain <auto-default> (i=29, p=100)
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5004] dns-mgr: plugin: settings: ifindex=29, priority=100, default-route=1, search=, reverse=40.202.49.10.in-addr.arpa,41.202.49.10.in-addr.arpa,4>
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5005] dns-mgr: plugin: add domain <auto-default> (i=29, p=100)
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5005] dns-mgr: plugin: settings: ifindex=29, priority=100, default-route=1, search=, reverse=e.7.7.c.5.b.6.0.1.2.1.2.2.0.a.2.ip6.arpa
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5005] dns-mgr: plugin: add domain 'mork.no' (i=3, p=100)
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5005] dns-mgr: plugin: add domain <auto-default> (i=3, p=100)
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5005] dns-mgr: plugin: settings: ifindex=3, priority=100, default-route=1, search=mork.no, reverse=10.168.192.in-addr.arpa
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5005] dns-mgr: plugin: add domain <auto-default> (i=3, p=100)
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5006] dns-mgr: plugin: settings: ifindex=3, priority=100, default-route=1, search=, reverse=a.0.b.4.4.6.9.0.9.9.7.0.1.0.a.2.ip6.arpa,0.0.0.0.0.0.0>
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5008] dns-mgr: update-resolv-no-stub: '/run/NetworkManager/no-stub-resolv.conf' successfully written
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5108] dns-mgr: update-resolv-conf: write to /etc/resolv.conf succeeded (rc-manager=symlink)
Jun 24 14:37:55 miraculix NetworkManager[1565954]: <trace> [1687610275.5108] dns-mgr: update-resolv-conf: write internal file /run/NetworkManager/resolv.conf succeeded

I don't exactly understand what this means, but it looks like
NetworkManager considers all 8 DNS servers equal ("best")?  With both
links having "priority=100, default-route=1".

This does not reflect the actual priority, as shown above, where the
wlan0 (ifindex=3) link has a lowe metric than the wwan0 (ifindex=29)
link.

Anyone have a clue why this happens?

Bjørn