net/dns: print systemd-resolved ResolvConfMode

The ResolvConfMode property is documented to return how systemd-resolved
is currently managing /etc/resolv.conf. Include that information in the
debug line, when available, to assist in debugging DNS issues.

Signed-off-by: Andrew Dunham <andrew@du.nham.ca>
Change-Id: I1ae3a257df1d318d0193a8c7f135c458ec45093e

net/dns/manager_linux.go

@@ -31,6 +31,7 @@ func NewOSConfigurator(logf logger.Logf, interfaceName string) (ret OSConfigurat
 	env := newOSConfigEnv{
 		fs:                directFS{},
 		dbusPing:          dbusPing,
+		dbusReadString:    dbusReadString,
 		nmIsUsingResolved: nmIsUsingResolved,
 		nmVersionBetween:  nmVersionBetween,
 		resolvconfStyle:   resolvconfStyle,
@@ -60,6 +61,7 @@ func NewOSConfigurator(logf logger.Logf, interfaceName string) (ret OSConfigurat
 type newOSConfigEnv struct {
 	fs                        wholeFileFS
 	dbusPing                  func(string, string) error
+	dbusReadString            func(string, string, string, string) (string, error)
 	nmIsUsingResolved         func() error
 	nmVersionBetween          func(v1, v2 string) (safe bool, err error)
 	resolvconfStyle           func() string
@@ -78,6 +80,25 @@ func dnsMode(logf logger.Logf, env newOSConfigEnv) (ret string, err error) {
 		logf("dns: %v", debug)
 	}()
 
+	// In all cases that we detect systemd-resolved, try asking it what it
+	// thinks the current resolv.conf mode is so we can add it to our logs.
+	defer func() {
+		if ret != "systemd-resolved" {
+			return
+		}
+
+		// Try to ask systemd-resolved what it thinks the current
+		// status of resolv.conf is. This is documented at:
+		//    https://www.freedesktop.org/software/systemd/man/org.freedesktop.resolve1.html
+		mode, err := env.dbusReadString("org.freedesktop.resolve1", "/org/freedesktop/resolve1", "org.freedesktop.resolve1.Manager", "ResolvConfMode")
+		if err != nil {
+			logf("dns: ResolvConfMode error: %v", err)
+			dbg("resolv-conf-mode", "error")
+		} else {
+			dbg("resolv-conf-mode", mode)
+		}
+	}()
+
 	// Before we read /etc/resolv.conf (which might be in a broken
 	// or symlink-dangling state), try to ping the D-Bus service
 	// for systemd-resolved. If it's active on the machine, this
@@ -102,6 +123,7 @@ func dnsMode(logf logger.Logf, env newOSConfigEnv) (ret string, err error) {
 	switch resolvOwner(bs) {
 	case "systemd-resolved":
 		dbg("rc", "resolved")
+
 		// Some systems, for reasons known only to them, have a
 		// resolv.conf that has the word "systemd-resolved" in its
 		// header, but doesn't actually point to resolved. We mustn't
@@ -327,3 +349,29 @@ func dbusPing(name, objectPath string) error {
 	call := obj.CallWithContext(ctx, "org.freedesktop.DBus.Peer.Ping", 0)
 	return call.Err
 }
+
+// dbusReadString reads a string property from the provided name and object
+// path. property must be in "interface.member" notation.
+func dbusReadString(name, objectPath, iface, member string) (string, error) {
+	conn, err := dbus.SystemBus()
+	if err != nil {
+		// DBus probably not running.
+		return "", err
+	}
+
+	ctx, cancel := context.WithTimeout(context.Background(), time.Second)
+	defer cancel()
+
+	obj := conn.Object(name, dbus.ObjectPath(objectPath))
+
+	var result dbus.Variant
+	err = obj.CallWithContext(ctx, "org.freedesktop.DBus.Properties.Get", 0, iface, member).Store(&result)
+	if err != nil {
+		return "", err
+	}
+
+	if s, ok := result.Value().(string); ok {
+		return s, nil
+	}
+	return result.String(), nil
+}

net/dns/manager_linux_test.go

@@ -71,7 +71,7 @@ func TestLinuxDNSMode(t *testing.T) {
 		{
 			name:    "resolved_alone_without_ping",
 			env:     env(resolvDotConf("# Managed by systemd-resolved", "nameserver 127.0.0.53")),
-			wantLog: "dns: [rc=resolved nm=no ret=systemd-resolved]",
+			wantLog: "dns: ResolvConfMode error: dbus property not found\ndns: [rc=resolved nm=no resolv-conf-mode=error ret=systemd-resolved]",
 			want:    "systemd-resolved",
 		},
 		{
@@ -79,7 +79,7 @@ func TestLinuxDNSMode(t *testing.T) {
 			env: env(
 				resolvDotConf("# Managed by systemd-resolved", "nameserver 127.0.0.53"),
 				resolvedRunning()),
-			wantLog: "dns: [resolved-ping=yes rc=resolved nm=no ret=systemd-resolved]",
+			wantLog: "dns: [resolved-ping=yes rc=resolved nm=no resolv-conf-mode=fortests ret=systemd-resolved]",
 			want:    "systemd-resolved",
 		},
 		{
@@ -88,7 +88,7 @@ func TestLinuxDNSMode(t *testing.T) {
 				resolvDotConf("# Managed by systemd-resolved", "nameserver 127.0.0.53"),
 				resolvedRunning(),
 				nmRunning("1.2.3", false)),
-			wantLog: "dns: [resolved-ping=yes rc=resolved nm=yes nm-resolved=no ret=systemd-resolved]",
+			wantLog: "dns: [resolved-ping=yes rc=resolved nm=yes nm-resolved=no resolv-conf-mode=fortests ret=systemd-resolved]",
 			want:    "systemd-resolved",
 		},
 		{
@@ -106,7 +106,7 @@ func TestLinuxDNSMode(t *testing.T) {
 				resolvDotConf("# Managed by systemd-resolved", "nameserver 127.0.0.53"),
 				resolvedRunning(),
 				nmRunning("1.27.0", true)),
-			wantLog: "dns: [resolved-ping=yes rc=resolved nm=yes nm-resolved=yes nm-safe=no ret=systemd-resolved]",
+			wantLog: "dns: [resolved-ping=yes rc=resolved nm=yes nm-resolved=yes nm-safe=no resolv-conf-mode=fortests ret=systemd-resolved]",
 			want:    "systemd-resolved",
 		},
 		{
@@ -115,7 +115,7 @@ func TestLinuxDNSMode(t *testing.T) {
 				resolvDotConf("# Managed by systemd-resolved", "nameserver 127.0.0.53"),
 				resolvedRunning(),
 				nmRunning("1.22.0", true)),
-			wantLog: "dns: [resolved-ping=yes rc=resolved nm=yes nm-resolved=yes nm-safe=no ret=systemd-resolved]",
+			wantLog: "dns: [resolved-ping=yes rc=resolved nm=yes nm-resolved=yes nm-safe=no resolv-conf-mode=fortests ret=systemd-resolved]",
 			want:    "systemd-resolved",
 		},
 		// Regression tests for extreme corner cases below.
@@ -141,7 +141,7 @@ func TestLinuxDNSMode(t *testing.T) {
 					"nameserver 127.0.0.53",
 					"nameserver 127.0.0.53"),
 				resolvedRunning()),
-			wantLog: "dns: [resolved-ping=yes rc=resolved nm=no ret=systemd-resolved]",
+			wantLog: "dns: [resolved-ping=yes rc=resolved nm=no resolv-conf-mode=fortests ret=systemd-resolved]",
 			want:    "systemd-resolved",
 		},
 		{
@@ -156,7 +156,7 @@ func TestLinuxDNSMode(t *testing.T) {
 				"# run \"systemd-resolve --status\" to see details about the actual nameservers.",
 				"nameserver 127.0.0.53"),
 				resolvedRunning()),
-			wantLog: "dns: [resolved-ping=yes rc=resolved nm=no ret=systemd-resolved]",
+			wantLog: "dns: [resolved-ping=yes rc=resolved nm=no resolv-conf-mode=fortests ret=systemd-resolved]",
 			want:    "systemd-resolved",
 		},
 		{
@@ -171,7 +171,7 @@ func TestLinuxDNSMode(t *testing.T) {
 				"# 127.0.0.53 is the systemd-resolved stub resolver.",
 				"# run \"systemd-resolve --status\" to see details about the actual nameservers.",
 				"nameserver 127.0.0.53")),
-			wantLog: "dns: [rc=resolved nm=no ret=systemd-resolved]",
+			wantLog: "dns: ResolvConfMode error: dbus property not found\ndns: [rc=resolved nm=no resolv-conf-mode=error ret=systemd-resolved]",
 			want:    "systemd-resolved",
 		},
 		{
@@ -183,7 +183,7 @@ func TestLinuxDNSMode(t *testing.T) {
 				"options edns0 trust-ad"),
 				resolvedRunning(),
 				nmRunning("1.32.12", true)),
-			wantLog: "dns: [resolved-ping=yes rc=nm nm-resolved=yes nm-safe=no ret=systemd-resolved]",
+			wantLog: "dns: [resolved-ping=yes rc=nm nm-resolved=yes nm-safe=no resolv-conf-mode=fortests ret=systemd-resolved]",
 			want:    "systemd-resolved",
 		},
 		{
@@ -194,7 +194,7 @@ func TestLinuxDNSMode(t *testing.T) {
 				"nameserver 127.0.0.53",
 				"options edns0 trust-ad"),
 				nmRunning("1.32.12", true)),
-			wantLog: "dns: [rc=nm nm-resolved=yes nm-safe=no ret=systemd-resolved]",
+			wantLog: "dns: ResolvConfMode error: dbus property not found\ndns: [rc=nm nm-resolved=yes nm-safe=no resolv-conf-mode=error ret=systemd-resolved]",
 			want:    "systemd-resolved",
 		},
 		{
@@ -217,7 +217,7 @@ func TestLinuxDNSMode(t *testing.T) {
 				"nameserver 127.0.0.53",
 				"options edns0 trust-ad"),
 				resolvedRunning()),
-			wantLog: "dns: [resolved-ping=yes rc=nm nm-resolved=yes nm=no ret=systemd-resolved]",
+			wantLog: "dns: [resolved-ping=yes rc=nm nm-resolved=yes nm=no resolv-conf-mode=fortests ret=systemd-resolved]",
 			want:    "systemd-resolved",
 		},
 		{
@@ -228,7 +228,7 @@ func TestLinuxDNSMode(t *testing.T) {
 				"search lan",
 				"nameserver 127.0.0.53"),
 				resolvedRunning()),
-			wantLog: "dns: [resolved-ping=yes rc=nm nm-resolved=yes nm=no ret=systemd-resolved]",
+			wantLog: "dns: [resolved-ping=yes rc=nm nm-resolved=yes nm=no resolv-conf-mode=fortests ret=systemd-resolved]",
 			want:    "systemd-resolved",
 		},
 		{
@@ -236,8 +236,9 @@ func TestLinuxDNSMode(t *testing.T) {
 			// before we read its file.
 			env: env(resolvedStartOnPingAndThen(
 				resolvDotConf("# Managed by systemd-resolved", "nameserver 127.0.0.53"),
+				resolvedDbusProperty(),
 			)),
-			wantLog: "dns: [resolved-ping=yes rc=resolved nm=no ret=systemd-resolved]",
+			wantLog: "dns: [resolved-ping=yes rc=resolved nm=no resolv-conf-mode=fortests ret=systemd-resolved]",
 			want:    "systemd-resolved",
 		},
 	}
@@ -306,9 +307,16 @@ type dbusService struct {
 	hook       func() // if non-nil, run on ping
 }
 
+type dbusProperty struct {
+	name, path    string
+	iface, member string
+	hook          func() (string, error) // what to return
+}
+
 type envBuilder struct {
 	fs              memFS
 	dbus            []dbusService
+	dbusProperties  []dbusProperty
 	nmUsingResolved bool
 	nmVersion       string
 	resolvconfStyle string
@@ -345,6 +353,14 @@ func env(opts ...envOption) newOSConfigEnv {
 			}
 			return errors.New("dbus service not found")
 		},
+		dbusReadString: func(name, path, iface, member string) (string, error) {
+			for _, svc := range b.dbusProperties {
+				if svc.name == name && svc.path == path && svc.iface == iface && svc.member == member {
+					return svc.hook()
+				}
+			}
+			return "", errors.New("dbus property not found")
+		},
 		nmIsUsingResolved: func() error {
 			if !b.nmUsingResolved {
 				return errors.New("networkmanager not using resolved")
@@ -365,9 +381,16 @@ func resolvDotConf(ss ...string) envOption {
 	})
 }
 
-// resolvedRunning returns an option that makes resolved reply to a dbusPing.
+// resolvedRunning returns an option that makes resolved reply to a dbusPing
+// and the ResolvConfMode property.
 func resolvedRunning() envOption {
-	return resolvedStartOnPingAndThen( /* nothing */ )
+	return resolvedStartOnPingAndThen(resolvedDbusProperty())
+}
+
+// resolvedDbusProperty returns an option that responds to the ResolvConfMode
+// property that resolved exposes.
+func resolvedDbusProperty() envOption {
+	return setDbusProperty("org.freedesktop.resolve1", "/org/freedesktop/resolve1", "org.freedesktop.resolve1.Manager", "ResolvConfMode", "fortests")
 }
 
 // resolvedStartOnPingAndThen returns an option that makes resolved be
@@ -400,3 +423,17 @@ func resolvconf(s string) envOption {
 		b.resolvconfStyle = s
 	})
 }
+
+func setDbusProperty(name, path, iface, member, value string) envOption {
+	return envOpt(func(b *envBuilder) {
+		b.dbusProperties = append(b.dbusProperties, dbusProperty{
+			name:   name,
+			path:   path,
+			iface:  iface,
+			member: member,
+			hook: func() (string, error) {
+				return value, nil
+			},
+		})
+	})
+}