Network Manager + OpenVPN does not respond to DNS server change on second connection attempt

[WalterNicholls]

Scenario:
Discovered on Kubuntu 16.10, upgraded from a fresh install of 16.04. While I only have the one computer to test with, the 16.10 is definitely relevant (I did not have this problem on 16.04) but I can't tell if the upgrade is part of it, (the upgrade may or may not be relevant).

Have "full time" wired or wireless connection (does not matter which used)
Part time OpenVPN connection set up via NetworkManager.

Steps to reproduce
1. Fresh boot
2. ping a device on the VPN network (eg amachine.remotelan ) Result: "ping: amachine.remotelan: Name or service not known"
3. Connect to the VPN service via Network Manager.
4. ping amachine.remotelan - result:
 PING amachine.remotelan (192.168.68.44) 56(84) bytes of data.
  64 bytes from amachine.remotelan (192.168.68.44): icmp_seq=1 ttl=127 time=7.75 ms
5. Disconnect from the VPN service again.
  ping result again "ping: amachine.remotelan: Name or service not known"

6. Reconnect to the VPN again, and ping again

Observed:
   "ping: amachine.remotelan: Name or service not known"

  However "ping 192.168.68.44" responds successfully as expected

Expected:
    PING ... 192.168.... 64 bytes from .. etc to the ping by name

---------------
Further info I'm going to add in a subsequent comment. (just annotating syslog right now!)

[WalterNicholls (walter-nic)]

Remote VPN is pfSense 2.3.2

From syslog, expurgated (but not tampered with, no real secrets here):

:: Here's the WiFi coming up (showing local LAN) ::
Nov 23 19:06:41 rukbat dhclient[2169]: DHCPACK of 192.168.33.117 from 192.168.33.1
Nov 23 19:06:41 rukbat NetworkManager[1216]: <info> [1479881201.2161] address 192.168.33.117
Nov 23 19:06:41 rukbat NetworkManager[1216]: <info> [1479881201.2161] plen 24 (255.255.255.0)
...
Nov 23 19:06:41 rukbat NetworkManager[1216]: <info> [1479881201.2161] nameserver '192.168.33.1'
...
Nov 23 19:06:41 rukbat NetworkManager[1216]: <info> [1479881201.2162] dhcp4 (wlo1): state changed unknown -> bound
...
Nov 23 19:06:41 rukbat systemd-resolved[1282]: Switching to system DNS server 127.0.1.1.
...

:: Then here is the VPN coming up for the FIRST time ::
..
Nov 23 19:06:45 rukbat NetworkManager[1216]: <info> [1479881205.3847] audit: op="connection-activate" uuid="b53b592d-724d-44bf-a2c4-b7fe818add43" name="Berlin VPN" pid=1979 uid=1000 result="success"
Nov 23 19:06:45 rukbat NetworkManager[1216]: <info> [1479881205.3893] vpn-connection[0x55cd7969d200,b53b592d-724d-44bf-a2c4-b7fe818add43,"Berlin VPN",0]: Started the VPN service, PID 2379
Nov 23 19:06:45 rukbat NetworkManager[1216]: <info> [1479881205.3952] vpn-connection[0x55cd7969d200,b53b592d-724d-44bf-a2c4-b7fe818add43,"Berlin VPN",0]: Saw the service appear; activating connection
..
Nov 23 19:06:57 rukbat NetworkManager[1216]: <info> [1479881217.9795] dns-mgr: Writing DNS information to /sbin/resolvconf
Nov 23 19:06:57 rukbat dnsmasq[2179]: setting upstream servers from DBus
Nov 23 19:06:57 rukbat dnsmasq[2179]: using nameserver 192.168.33.1#53(via wlo1)
Nov 23 19:06:57 rukbat dnsmasq[2179]: using nameserver fd00::a96:d7ff:feb9:dbe7#53(via wlo1)
Nov 23 19:06:57 rukbat dnsmasq[2179]: using nameserver 192.168.68.1#53 for domain csl
Nov 23 19:06:57 rukbat dnsmasq[2179]: using nameserver 192.168.68.1#53 for domain 26.70.168.192.in-addr.arpa
Nov 23 19:06:57 rukbat dnsmasq[2179]: using nameserver 192.168.68.1#53 for domain 68.168.192.in-addr.arpa
Nov 23 19:06:57 rukbat dnsmasq[2179]: using nameserver 192.168.68.1#53 for domain 70.168.192.in-addr.arpa
...
Nov 23 19:07:04 rukbat systemd-timesyncd[990]: Synchronized to time server 91.189.91.157:123 (ntp.ubuntu.com).
Nov 23 19:07:04 rukbat systemd-resolved[1282]: Using degraded feature set (UDP) for DNS server 127.0.1.1.

:: Now I disconnect from the VPN ::
Nov 23 19:07:18 rukbat NetworkManager[1216]: <info> [1479881238.8632] audit: op="connection-deactivate" uuid="b53b592d-724d-44bf-a2c4-b7fe818add43" name="Berlin VPN" pid=1979 uid=1000 result="success"
Nov 23 19:07:18 rukbat NetworkManager[1216]: <info> [1479881238.8635] dns-mgr: Writing DNS information to /sbin/resolvconf
Nov 23 19:07:18 rukbat dnsmasq[2179]: setting upstream servers from DBus
Nov 23 19:07:18 rukbat dnsmasq[2179]: using nameserver 192.168.33.1#53(via wlo1)
...
Nov 23 19:07:23 rukbat NetworkManager[1216]: nm-openvpn[2379] <info> openvpn[2382] exited with success
Nov 23 19:07:23 rukbat nm-dispatcher: req:2 'down' [tun0]: start running ordered scripts...

:: And now reconnecting again ::
Nov 23 19:07:27 rukbat NetworkManager[121...

[WalterNicholls (walter-nic)]

Finally see Bug #1211110 particularly the later (November 2016) comments

[WalterNicholls (walter-nic)]

/etc/NetworkManager/NetworkManager.conf contains:

[main]
plugins=ifupdown,keyfile,ofono
dns=dnsmasq

[ifupdown]
managed=false

(There are various posts floating around to the effect that 'dns=dnsmasq' should be commented out. However this is how the Ubuntu install set it so assuming that either it is critical to correct operation or it is part of the cause).

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Andrea Lazzarotto (Lazza) (andrea-lazzarotto)]

I confirm the issue. One detail that should be noted is that during the first connection DNS works, but it leaks! I.e. if you are using a VPN service for privacy purposes you'd expect NM to pick up the DNS settings from the VPN provider (like openvpn from terminal does) and don't use your home router as a DNS server while the VPN is on.

Subsequent connections don't have any DNS working, not even a leaky one.

[WalterNicholls (walter-nic)]

Re "if you are using a VPN service for privacy purposes" - I have a contrary use case. I want to use my home router as much as possible, and the VPN (which may be my office network, or more critically a client's network) *only* for traffic required to go there.
My understanding was that this was controlled by the checkebox "Use only for resources on this connection" - although, by the sounds of it, that only affects routing of traffic not DNS lookups (it *is* on the Routes.. subdialog)

traceroute to bugs.launchpad.net (91.189.89.225), 30 hops max, 60 byte packets
 1 192.168.33.1 1.615 ms 2.487 ms 2.673 ms <== home router
 2 ....

traceroute to 192.168.68.44 (192.168.68.44), <== a resource on the remote LAN
 1 192.168.70.1 7.561 ms 9.173 ms 10.266 ms <== VPN gateway
 2 ....

I can't check just now whether DNS queries are going where I intend or not - I'll have to reboot to get a working VPN link (Refer to Bug #1644098 <g>)

[WalterNicholls (walter-nic)]

Looks like finding out what DNS server is *asked* about a query (add log-queries to dnsmasq.conf) is going to require another reboot : if I restart NetworkManager then the VPN connection will also restart .. circular reference to this bug again. I can't afford to keep doing this during a work day!

[WalterNicholls (walter-nic)]

FWIW on my laptop (16.10) DNS queries are working as I wish it (ie "correctly"). With VPN disconnected all queries are going to the home router (192.168.33.1), queries for eg amachine.csl are sent there and come back NXDOMAIN.
With VPN connected, queries on .csl are going to the remote VPN server (as requested for this domain suffix by the VPN server: no configuration on my local machine here). Queries for anything else go to home router.

So dnsmasq logs this:
  Nov 24 15:18:24 rukbat dnsmasq[6655]: query[A] amachine.csl from 127.0.0.1
  Nov 24 15:18:24 rukbat dnsmasq[6655]: forwarded amachine.csl to 192.168.68.1
  Nov 24 15:18:24 rukbat dnsmasq[6655]: reply amachine.csl is 192.168.68.44

HOWEVER, after disconnecting and then reconnecting VPN, despite dnsmasq having noted this during the VPN connection set up:

   Nov 24 15:24:51 rukbat dnsmasq[6655]: using nameserver 192.168.68.1#53 for domain csl

Now a request for say www.bbc.co.uk correctly goes through the home router:

   Nov 24 15:30:05 rukbat dnsmasq[6655]: query[A] www.bbc.co.uk from 127.0.0.1
   Nov 24 15:30:05 rukbat dnsmasq[6655]: forwarded www.bbc.co.uk to 192.168.33.1
   Nov 24 15:30:05 rukbat dnsmasq[6655]: reply www.bbc.co.uk is <CNAME>
   Nov 24 15:30:05 rukbat dnsmasq[6655]: reply www.bbc.net.uk is 212.58.246.55

But a request for anothermachine.csl , only this is logged:

   Nov 24 15:26:13 rukbat dnsmasq[6655]: query[A] anothermachine.csl from 127.0.0.1

That's right, no "forwarded", no "reply" and the output of / dig anothermachine.csl / has no answer:
  ;; QUESTION SECTION:
  ;anothermachine.csl. IN A

  ;; Query time: 0 msec
  ;; SERVER: 127.0.1.1#53(127.0.1.1)

In other words, dnsmasq doesn't even try. Looks like a bug in dnsmasq (or a bug in Network Manager not instructing dnsmasq correctly).

[Till Schäfer (till2-schaefer)]

I have the same issue on Gentoo using NetworkManager 1.4.0 and networkmanager-openvpn 1.2.6.

-> seems to be an upstream issue

the interesting part here is, that the log files still show an update to dnsmasq in during the second connection attempt:

Dez 05 17:04:22 somecomputername dnsmasq[16697]: using nameserver 172.16.0.1#53 for domain somedomain.net

[Till Schäfer (till2-schaefer)]

upstream bug report: https://bugzilla.gnome.org/show_bug.cgi?id=775655

[Colin Law (colin-law)]

I don't know whether it is significant but I notice in syslog that for the second connection to the vpn I see the additional line

systemd-resolved[1001]: Using degraded feature set (UDP+EDNS0+DO) for DNS server 127.0.1.1.

and I notice that a similar message is present in the log in comment #1

[Till Schäfer (till2-schaefer)]

The bug is cause by a dnsmasq bug described in the following bug report:

https://bugzilla.redhat.com/show_bug.cgi?id=1367772

and is fixed by applying the following path to dnsmasq (2.76):

http://thekelleys.org.uk/gitweb/?p=dnsmasq.git;a=commitdiff;h=2675f2061525bc954be14988d64384b74aa7bf8b

[Daniel (danito8905)]

I have the same issue (Kubuntu 16.10 + Backports).

I solved it by installing the "dnsmasq" package.

I had only "dnsmasq-base" installed.

[Daniel (danito8905)]

I had to uninstall the package "dnsmasq" because I had problems resolving the domains that should work (eg youtube) even with the vpn disconnected, it had weird behavior.

I continue restarting the service "network-manager" to be able to reconnect correctly to the vpn.

[icesmurf (icesmurf)]

cat << EOF > /etc/network/if-up.d/zz_restart_dnsmasq
#!/bin/bash
if [[ "\$IFACE" =~ [^tun] ]]; then
  sleep 2
  logger "** Restarting DNSMASQ process because funky network manager crappyness"
  kill \`cat /var/run/NetworkManager/dnsmasq.pid\`
fi
EOF

chmod 755 /etc/network/if-up.d/zz_restart_dnsmasq

Seems to consistently fix the issue for me, nasty hack but meh, works.