Send SIGUSR1 to dnsmasq periodically

This adds a feature flag --logInterval for periodic triggering dnsmasq
to log its statistics by sending SIGUSR1 to it.

The new motivation for adding this feature comes from the recently
added dnsmasq flag --max-tcp-connections and the related statistics of
TCP connection utilisation being added to the log output triggered
by SIGUSR1.

Author: DamianSawicki

cmd/dnsmasq-nanny/main.go

@@ -37,6 +37,7 @@ var (
 		RunNannyOpts: dnsmasq.RunNannyOpts{
 			DnsmasqExec:     "/usr/sbin/dnsmasq",
 			RestartOnChange: false,
+			LogInterval:     time.Duration(0),
 		},
 		configDir:     "/etc/k8s/dns/dnsmasq-nanny",
 		syncInterval:  10 * time.Second,
@@ -69,6 +70,9 @@ Any arguments given after "--" will be passed directly to dnsmasq itself.
 		"interval to check for configuration updates")
 	flag.StringVar(&opts.kubednsServer, "kubednsServer", opts.kubednsServer,
 		"local kubedns instance address for non-IP name resolution")
+	flag.DurationVar(&opts.LogInterval, "logInterval",
+		opts.LogInterval,
+		"interval to send SIGUSR1 to dnsmasq which triggers statistics logging")
 	klog.InitFlags(nil)
 	flag.Parse()
 }

pkg/dnsmasq/nanny.go

@@ -24,6 +24,8 @@ import (
 	"net"
 	"os/exec"
 	"strings"
+	"syscall"
+	"time"
 
 	"k8s.io/dns/pkg/dns/config"
 	"k8s.io/klog/v2"
@@ -176,7 +178,6 @@ func (n *Nanny) Kill() error {
 	}
 
 	if err := n.cmd.Process.Kill(); err != nil {
-		klog.Errorf("Error killing dnsmasq: %v", err)
 		return err
 	}
 
@@ -185,6 +186,17 @@ func (n *Nanny) Kill() error {
 	return nil
 }
 
+// Send SIGUSR1 to dnsmasq (which makes dnsmasq log statistics).
+func (n *Nanny) SendSIGUSR1() error {
+	if n.cmd == nil {
+		return fmt.Errorf("Process is not running")
+	}
+	if err := n.cmd.Process.Signal(syscall.SIGUSR1); err != nil {
+		return err
+	}
+	return nil
+}
+
 // RunNannyOpts for running the nanny.
 type RunNannyOpts struct {
 	// Location of the dnsmasq executable.
@@ -193,6 +205,8 @@ type RunNannyOpts struct {
 	DnsmasqArgs []string
 	// Restart the daemon on ConfigMap changes.
 	RestartOnChange bool
+	// Interval for triggering dnsmasq to log its statistics by sending SIGUSR1.
+	LogInterval time.Duration
 }
 
 // RunNanny runs the nanny and handles configuration updates.
@@ -211,6 +225,11 @@ func RunNanny(sync config.Sync, opts RunNannyOpts, kubednsServer string) {
 		klog.Fatalf("Could not start dnsmasq with initial configuration: %v", err)
 	}
 
+	logChannel := make(<-chan time.Time)
+	if opts.LogInterval != 0 {
+		logChannel = time.NewTicker(opts.LogInterval).C
+	}
+
 	configChan := sync.Periodic()
 
 	for {
@@ -222,14 +241,22 @@ func RunNanny(sync config.Sync, opts RunNannyOpts, kubednsServer string) {
 		case currentConfig = <-configChan:
 			if opts.RestartOnChange {
 				klog.V(0).Infof("Restarting dnsmasq with new configuration")
-				nanny.Kill()
+				if err := nanny.Kill(); err != nil {
+					klog.Errorf("Error killing dnsmasq: %v", err)
+				}
 				nanny = &Nanny{Exec: opts.DnsmasqExec}
 				nanny.Configure(opts.DnsmasqArgs, currentConfig, kubednsServer)
-				nanny.Start()
+				if err := nanny.Start(); err != nil {
+					klog.Errorf("Could not start dnsmasq with new configuration: %v", err)
+				}
 			} else {
 				klog.V(2).Infof("Not restarting dnsmasq (--restartDnsmasq=false)")
 			}
 			break
+		case <-logChannel:
+			if err := nanny.SendSIGUSR1(); err != nil {
+				klog.Warningf("Error sending SIGUSR1 to dnsmasq: %v", err)
+			}
 		}
 	}
 }

pkg/dnsmasq/nanny_test.go

@@ -163,4 +163,24 @@ func TestNannyLifecycle(t *testing.T) {
 	time.Sleep(250 * time.Millisecond)
 	gomega.Expect(nanny.Kill()).To(gomega.Succeed())
 	gomega.Expect(nanny.Kill()).NotTo(gomega.Succeed())
+
+	// Send SIGUSR1.
+	nanny = &Nanny{Exec: mockDnsmasq}
+	nanny.Configure(
+		[]string{"--trapTwice"},
+		&config.Config{},
+		kubednsServer)
+	gomega.Expect(nanny.Start()).To(gomega.Succeed())
+	time.Sleep(time.Second)
+	gomega.Expect(nanny.SendSIGUSR1()).To(gomega.Succeed())
+	time.Sleep(250 * time.Millisecond)
+	running := true // Dnsmasq reacts on SIGUSR1 and continues.
+	select {
+	case _ = <-nanny.ExitChannel:
+		running = false
+	default:
+	}
+	gomega.Expect(running).To(gomega.BeTrue())
+	gomega.Expect(nanny.SendSIGUSR1()).To(gomega.Succeed()) // mockDnsmasq with --trapTwice successfully exits after receiving the second SIGUSR1.
+	gomega.Expect(<-nanny.ExitChannel).To(gomega.Succeed())
 }

test/fixtures/mock-dnsmasq.sh

@@ -37,6 +37,21 @@ sleepThenError() {
 	exit 1
 }
 
+COUNT=0
+exitOnSecondCall() {
+	: $((COUNT+=1))
+	echo "Function call no ${COUNT}"
+	if [ $COUNT -ge 2 ]; then
+		exit 0
+	fi
+}
+
+trapTwice() {
+	trap exitOnSecondCall USR1
+	echo "Trap registered"
+	runForever
+}
+
 ARGS="$*"
 RUN=
 
@@ -50,6 +65,7 @@ while [ ! -z "$1" ]; do
 		--exitWithSuccess) RUN=exitWithSuccess;;
 		--runForever)      RUN=runForever;;
 		--sleepThenError)  RUN=sleepThenError;;
+		--trapTwice)       RUN=trapTwice;;
 	esac
 	shift
 done