Quietly log error on UDP_NETRESET ioctl on Windows. (#1453) (#1568)

Co-authored-by: brad-defined <77982333+brad-defined@users.noreply.github.com>

Author: nbrownus

udp/udp_generic.go

@@ -10,9 +10,11 @@ package udp
 
 import (
 	"context"
+	"errors"
 	"fmt"
 	"net"
 	"net/netip"
+	"time"
 
 	"github.com/sirupsen/logrus"
 	"github.com/slackhq/nebula/config"
@@ -74,12 +76,22 @@ type rawMessage struct {
 func (u *GenericConn) ListenOut(r EncReader) {
 	buffer := make([]byte, MTU)
 
+	var lastRecvErr time.Time
+
 	for {
 		// Just read one packet at a time
 		n, rua, err := u.ReadFromUDPAddrPort(buffer)
 		if err != nil {
-			u.l.WithError(err).Debug("udp socket is closed, exiting read loop")
-			return
+			if errors.Is(err, net.ErrClosed) {
+				u.l.WithError(err).Debug("udp socket is closed, exiting read loop")
+				return
+			}
+			// Dampen unexpected message warns to once per minute
+			if lastRecvErr.IsZero() || time.Since(lastRecvErr) > time.Minute {
+				lastRecvErr = time.Now()
+				u.l.WithError(err).Warn("unexpected udp socket receive error")
+			}
+			continue
 		}
 
 		r(netip.AddrPortFrom(rua.Addr().Unmap(), rua.Port()), buffer[:n])

udp/udp_rio_windows.go

@@ -14,6 +14,7 @@ import (
 	"sync"
 	"sync/atomic"
 	"syscall"
+	"time"
 	"unsafe"
 
 	"github.com/sirupsen/logrus"
@@ -66,7 +67,7 @@ func NewRIOListener(l *logrus.Logger, addr netip.Addr, port int) (*RIOConn, erro
 
 	u := &RIOConn{l: l}
 
-	err := u.bind(&windows.SockaddrInet6{Addr: addr.As16(), Port: port})
+	err := u.bind(l, &windows.SockaddrInet6{Addr: addr.As16(), Port: port})
 	if err != nil {
 		return nil, fmt.Errorf("bind: %w", err)
 	}
@@ -82,11 +83,11 @@ func NewRIOListener(l *logrus.Logger, addr netip.Addr, port int) (*RIOConn, erro
 	return u, nil
 }
 
-func (u *RIOConn) bind(sa windows.Sockaddr) error {
+func (u *RIOConn) bind(l *logrus.Logger, sa windows.Sockaddr) error {
 	var err error
 	u.sock, err = winrio.Socket(windows.AF_INET6, windows.SOCK_DGRAM, windows.IPPROTO_UDP)
 	if err != nil {
-		return err
+		return fmt.Errorf("winrio.Socket error: %w", err)
 	}
 
 	// Enable v4 for this socket
@@ -100,35 +101,40 @@ func (u *RIOConn) bind(sa windows.Sockaddr) error {
 	size := uint32(unsafe.Sizeof(flag))
 	err = syscall.WSAIoctl(syscall.Handle(u.sock), syscall.SIO_UDP_CONNRESET, (*byte)(unsafe.Pointer(&flag)), size, nil, 0, &ret, nil, 0)
 	if err != nil {
-		return err
+		// This is a best-effort to prevent errors from being returned by the udp recv operation.
+		// Quietly log a failure and continue.
+		l.WithError(err).Debug("failed to set UDP_CONNRESET ioctl")
 	}
+
 	ret = 0
 	flag = 0
 	size = uint32(unsafe.Sizeof(flag))
 	SIO_UDP_NETRESET := uint32(syscall.IOC_IN | syscall.IOC_VENDOR | 15)
 	err = syscall.WSAIoctl(syscall.Handle(u.sock), SIO_UDP_NETRESET, (*byte)(unsafe.Pointer(&flag)), size, nil, 0, &ret, nil, 0)
 	if err != nil {
-		return err
+		// This is a best-effort to prevent errors from being returned by the udp recv operation.
+		// Quietly log a failure and continue.
+		l.WithError(err).Debug("failed to set UDP_NETRESET ioctl")
 	}
 
 	err = u.rx.Open()
 	if err != nil {
-		return err
+		return fmt.Errorf("error rx.Open(): %w", err)
 	}
 
 	err = u.tx.Open()
 	if err != nil {
-		return err
+		return fmt.Errorf("error tx.Open(): %w", err)
 	}
 
 	u.rq, err = winrio.CreateRequestQueue(u.sock, packetsPerRing, 1, packetsPerRing, 1, u.rx.cq, u.tx.cq, 0)
 	if err != nil {
-		return err
+		return fmt.Errorf("error CreateRequestQueue: %w", err)
 	}
 
 	err = windows.Bind(u.sock, sa)
 	if err != nil {
-		return err
+		return fmt.Errorf("error windows.Bind(): %w", err)
 	}
 
 	return nil
@@ -137,15 +143,22 @@ func (u *RIOConn) bind(sa windows.Sockaddr) error {
 func (u *RIOConn) ListenOut(r EncReader) {
 	buffer := make([]byte, MTU)
 
+	var lastRecvErr time.Time
+
 	for {
 		// Just read one packet at a time
 		n, rua, err := u.receive(buffer)
+
 		if err != nil {
 			if errors.Is(err, net.ErrClosed) {
 				u.l.WithError(err).Debug("udp socket is closed, exiting read loop")
 				return
 			}
-			u.l.WithError(err).Error("unexpected udp socket receive error")
+			// Dampen unexpected message warns to once per minute
+			if lastRecvErr.IsZero() || time.Since(lastRecvErr) > time.Minute {
+				lastRecvErr = time.Now()
+				u.l.WithError(err).Warn("unexpected udp socket receive error")
+			}
 			continue
 		}