add stats.pprof flag to expose pprof on stats listener

cmd/nebula-service/main.go

@@ -78,16 +78,8 @@ func main() {
 	}
 
 	if !*configTest {
-		wait, err := ctrl.Start()
+		ctrl.Start()
-		if err != nil {
+		ctrl.ShutdownBlock()
-			util.LogWithContextIfNeeded("Error while running", err, l)
-			os.Exit(1)
-		}
-
-		go ctrl.ShutdownBlock()
-		wait()
-
-		l.Info("Goodbye")
 	}
 
 	os.Exit(0)

cmd/nebula/main.go

@@ -72,17 +72,9 @@ func main() {
 	}
 
 	if !*configTest {
-		wait, err := ctrl.Start()
+		ctrl.Start()
-		if err != nil {
-			util.LogWithContextIfNeeded("Error while running", err, l)
-			os.Exit(1)
-		}
-
-		go ctrl.ShutdownBlock()
 		notifyReady(l)
-		wait()
+		ctrl.ShutdownBlock()
-
-		l.Info("Goodbye")
 	}
 
 	os.Exit(0)

control.go

@@ -2,11 +2,9 @@ package nebula
 
 import (
 	"context"
-	"errors"
 	"net/netip"
 	"os"
 	"os/signal"
-	"sync"
 	"syscall"
 
 	"github.com/sirupsen/logrus"
@@ -15,16 +13,6 @@ import (
 	"github.com/slackhq/nebula/overlay"
 )
 
-type RunState int
-
-const (
-	Stopped  RunState = 0 // The control has yet to be started
-	Started  RunState = 1 // The control has been started
-	Stopping RunState = 2 // The control is stopping
-)
-
-var ErrAlreadyStarted = errors.New("nebula is already started")
-
 // Every interaction here needs to take extra care to copy memory and not return or use arguments "as is" when touching
 // core. This means copying IP objects, slices, de-referencing pointers and taking the actual value, etc
 
@@ -38,9 +26,6 @@ type controlHostLister interface {
 }
 
 type Control struct {
-	stateLock sync.Mutex
-	state     RunState
-
 	f                      *Interface
 	l                      *logrus.Logger
 	ctx                    context.Context
@@ -64,21 +49,10 @@ type ControlHostInfo struct {
 	CurrentRelaysThroughMe []netip.Addr     `json:"currentRelaysThroughMe"`
 }
 
-// Start actually runs nebula, this is a nonblocking call.
+// Start actually runs nebula, this is a nonblocking call. To block use Control.ShutdownBlock()
-// The returned function can be used to wait for nebula to fully stop.
+func (c *Control) Start() {
-func (c *Control) Start() (func(), error) {
-	c.stateLock.Lock()
-	if c.state != Stopped {
-		c.stateLock.Unlock()
-		return nil, ErrAlreadyStarted
-	}
-
 	// Activate the interface
-	err := c.f.activate()
+	c.f.activate()
-	if err != nil {
-		c.stateLock.Unlock()
-		return nil, err
-	}
 
 	// Call all the delayed funcs that waited patiently for the interface to be created.
 	if c.sshStart != nil {
@@ -98,33 +72,15 @@ func (c *Control) Start() (func(), error) {
 	}
 
 	// Start reading packets.
-	c.state = Started
+	c.f.run()
-	c.stateLock.Unlock()
-	return c.f.run()
-}
-
-func (c *Control) State() RunState {
-	c.stateLock.Lock()
-	defer c.stateLock.Unlock()
-	return c.state
 }
 
 func (c *Control) Context() context.Context {
 	return c.ctx
 }
 
-// Stop is a non-blocking call that signals nebula to close all tunnels and shut down
+// Stop signals nebula to shutdown and close all tunnels, returns after the shutdown is complete
 func (c *Control) Stop() {
-	c.stateLock.Lock()
-	if c.state != Started {
-		c.stateLock.Unlock()
-		// We are stopping or stopped already
-		return
-	}
-
-	c.state = Stopping
-	c.stateLock.Unlock()
-
 	// Stop the handshakeManager (and other services), to prevent new tunnels from
 	// being created while we're shutting them all down.
 	c.cancel()
@@ -133,7 +89,7 @@ func (c *Control) Stop() {
 	if err := c.f.Close(); err != nil {
 		c.l.WithError(err).Error("Close interface failed")
 	}
-	c.state = Stopped
+	c.l.Info("Goodbye")
 }
 
 // ShutdownBlock will listen for and block on term and interrupt signals, calling Control.Stop() once signalled

examples/config.yml

@@ -318,6 +318,11 @@ logging:
   #subsystem: nebula
   #interval: 10s
 
+  # enables pprof endpoints on the stats listener
+  # endpoints: /debug/pprof/, /debug/pprof/cmdline, /debug/pprof/profile,
+  #            /debug/pprof/symbol, /debug/pprof/trace
+  #pprof: false
+
   # enables counter metrics for meta packets
   #   e.g.: `messages.tx.handshake`
   # NOTE: `message.{tx,rx}.recv_error` is always emitted

interface.go

@@ -6,8 +6,8 @@ import (
 	"fmt"
 	"io"
 	"net/netip"
+	"os"
 	"runtime"
-	"sync"
 	"sync/atomic"
 	"time"
 
@@ -88,7 +88,6 @@ type Interface struct {
 
 	writers []udp.Conn
 	readers []io.ReadWriteCloser
-	wg      sync.WaitGroup
 
 	metricHandshakes    metrics.Histogram
 	messageMetrics      *MessageMetrics
@@ -211,7 +210,7 @@ func NewInterface(ctx context.Context, c *InterfaceConfig) (*Interface, error) {
 // activate creates the interface on the host. After the interface is created, any
 // other services that want to bind listeners to its IP may do so successfully. However,
 // the interface isn't going to process anything until run() is called.
-func (f *Interface) activate() error {
+func (f *Interface) activate() {
 	// actually turn on tun dev
 
 	addr, err := f.outside.LocalAddr()
@@ -239,38 +238,33 @@ func (f *Interface) activate() error {
 		if i > 0 {
 			reader, err = f.inside.NewMultiQueueReader()
 			if err != nil {
-				return err
+				f.l.Fatal(err)
 			}
 		}
 		f.readers[i] = reader
 	}
 
-	if err = f.inside.Activate(); err != nil {
+	if err := f.inside.Activate(); err != nil {
 		f.inside.Close()
-		return err
+		f.l.Fatal(err)
 	}
-
-	return nil
 }
 
-func (f *Interface) run() (func(), error) {
+func (f *Interface) run() {
 	// Launch n queues to read packets from udp
 	for i := 0; i < f.routines; i++ {
-		f.wg.Add(1)
 		go f.listenOut(i)
 	}
 
 	// Launch n queues to read packets from tun dev
 	for i := 0; i < f.routines; i++ {
-		f.wg.Add(1)
 		go f.listenIn(f.readers[i], i)
 	}
-
-	return f.wg.Wait, nil
 }
 
 func (f *Interface) listenOut(i int) {
 	runtime.LockOSThread()
+
 	var li udp.Conn
 	if i > 0 {
 		li = f.writers[i]
@@ -285,21 +279,14 @@ func (f *Interface) listenOut(i int) {
 	fwPacket := &firewall.Packet{}
 	nb := make([]byte, 12, 12)
 
-	err := li.ListenOut(func(fromUdpAddr netip.AddrPort, payload []byte) {
+	li.ListenOut(func(fromUdpAddr netip.AddrPort, payload []byte) {
 		f.readOutsidePackets(ViaSender{UdpAddr: fromUdpAddr}, plaintext[:0], payload, h, fwPacket, lhh, nb, i, ctCache.Get(f.l))
 	})
-
-	if err != nil && !f.closed.Load() {
-		f.l.WithError(err).Error("Error while reading packet inbound packet, closing")
-		//TODO: Trigger Control to close
-	}
-
-	f.l.Debugf("underlay reader %v is done", i)
-	f.wg.Done()
 }
 
 func (f *Interface) listenIn(reader io.ReadWriteCloser, i int) {
 	runtime.LockOSThread()
+
 	packet := make([]byte, mtu)
 	out := make([]byte, mtu)
 	fwPacket := &firewall.Packet{}
@@ -310,18 +297,17 @@ func (f *Interface) listenIn(reader io.ReadWriteCloser, i int) {
 	for {
 		n, err := reader.Read(packet)
 		if err != nil {
-			if !f.closed.Load() {
+			if errors.Is(err, os.ErrClosed) && f.closed.Load() {
-				f.l.WithError(err).Error("Error while reading outbound packet, closing")
+				return
-				//TODO: Trigger Control to close
 			}
-			break
+
+			f.l.WithError(err).Error("Error while reading outbound packet")
+			// This only seems to happen when something fatal happens to the fd, so exit.
+			os.Exit(2)
 		}
 
 		f.consumeInsidePacket(packet[:n], fwPacket, nb, out, i, conntrackCache.Get(f.l))
 	}
-
-	f.l.Debugf("overlay reader %v is done", i)
-	f.wg.Done()
 }
 
 func (f *Interface) RegisterConfigChangeCallbacks(c *config.C) {
@@ -498,23 +484,21 @@ func (f *Interface) GetCertState() *CertState {
 func (f *Interface) Close() error {
 	f.closed.Store(true)
 
-	// Release the udp readers
 	for _, u := range f.writers {
 		err := u.Close()
 		if err != nil {
 			f.l.WithError(err).Error("Error while closing udp socket")
 		}
 	}
-
-	// Release the tun readers
 	for i, r := range f.readers {
 		if i == 0 {
-			continue // f.readers[0] is f.inside, which we want to save for last, since it closes other stuff too
+			continue // f.readers[0] is f.inside, which we want to save for last
 		}
 		if err := r.Close(); err != nil {
 			f.l.WithError(err).Error("Error while closing tun reader")
 		}
 	}
 
+	// Release the tun device
 	return f.inside.Close()
 }

main.go

@@ -292,15 +292,15 @@ func Main(c *config.C, configTest bool, buildVersion string, logger *logrus.Logg
 	}
 
 	return &Control{
-		f:                      ifce,
+		ifce,
-		l:                      l,
+		l,
-		ctx:                    ctx,
+		ctx,
-		cancel:                 cancel,
+		cancel,
-		sshStart:               sshStart,
+		sshStart,
-		statsStart:             statsStart,
+		statsStart,
-		dnsStart:               dnsStart,
+		dnsStart,
-		lighthouseStart:        lightHouse.StartUpdateWorker,
+		lightHouse.StartUpdateWorker,
-		connectionManagerStart: connManager.Start,
+		connManager.Start,
 	}, nil
 }
 

overlay/tun_linux.go

@@ -72,11 +72,6 @@ type ifreqQLEN struct {
 }
 
 func newTunFromFd(c *config.C, l *logrus.Logger, deviceFd int, vpnNetworks []netip.Prefix) (*tun, error) {
-	err := unix.SetNonblock(deviceFd, true)
-	if err != nil {
-		return nil, err
-	}
-
 	file := os.NewFile(uintptr(deviceFd), "/dev/net/tun")
 
 	t, err := newTunGeneric(c, l, file, vpnNetworks)
@@ -127,11 +122,6 @@ func newTun(c *config.C, l *logrus.Logger, vpnNetworks []netip.Prefix, multiqueu
 	}
 	name := strings.Trim(string(req.Name[:]), "\x00")
 
-	err = unix.SetNonblock(fd, true)
-	if err != nil {
-		return nil, err
-	}
-
 	file := os.NewFile(uintptr(fd), "/dev/net/tun")
 	t, err := newTunGeneric(c, l, file, vpnNetworks)
 	if err != nil {
@@ -155,12 +145,7 @@ func newTunGeneric(c *config.C, l *logrus.Logger, file *os.File, vpnNetworks []n
 		l:                         l,
 	}
 
-	err := unix.SetNonblock(t.fd, true)
+	err := t.reload(c, true)
-	if err != nil {
-		return nil, err
-	}
-
-	err = t.reload(c, true)
 	if err != nil {
 		return nil, err
 	}
@@ -266,11 +251,6 @@ func (t *tun) NewMultiQueueReader() (io.ReadWriteCloser, error) {
 		return nil, err
 	}
 
-	err = unix.SetNonblock(fd, true)
-	if err != nil {
-		return nil, err
-	}
-
 	file := os.NewFile(uintptr(fd), "/dev/net/tun")
 
 	return file, nil
@@ -281,6 +261,29 @@ func (t *tun) RoutesFor(ip netip.Addr) routing.Gateways {
 	return r
 }
 
+func (t *tun) Write(b []byte) (int, error) {
+	var nn int
+	maximum := len(b)
+
+	for {
+		n, err := unix.Write(t.fd, b[nn:maximum])
+		if n > 0 {
+			nn += n
+		}
+		if nn == len(b) {
+			return nn, err
+		}
+
+		if err != nil {
+			return nn, err
+		}
+
+		if n == 0 {
+			return nn, io.ErrUnexpectedEOF
+		}
+	}
+}
+
 func (t *tun) deviceBytes() (o [16]byte) {
 	for i, c := range t.Device {
 		o[i] = byte(c)
@@ -709,17 +712,11 @@ func (t *tun) Close() error {
 	}
 
 	if t.ReadWriteCloser != nil {
-		err := t.ReadWriteCloser.Close()
+		_ = t.ReadWriteCloser.Close()
-		if err != nil {
-			t.l.WithField("error", err).Error("Failed to close read/write connection")
-		}
 	}
 
 	if t.ioctlFd > 0 {
-		err := os.NewFile(t.ioctlFd, "ioctlFd").Close()
+		_ = os.NewFile(t.ioctlFd, "ioctlFd").Close()
-		if err != nil {
-			t.l.WithField("error", err).Error("Failed to close ioctl fd")
-		}
 		t.ioctlFd = 0
 	}
 

service/service.go

@@ -44,10 +44,7 @@ type Service struct {
 }
 
 func New(control *nebula.Control) (*Service, error) {
-	wait, err := control.Start()
+	control.Start()
-	if err != nil {
-		return nil, err
-	}
 
 	ctx := control.Context()
 	eg, ctx := errgroup.WithContext(ctx)
@@ -144,12 +141,6 @@ func New(control *nebula.Control) (*Service, error) {
 		}
 	})
 
-	// Add the nebula wait function to the group
-	eg.Go(func() error {
-		wait()
-		return nil
-	})
-
 	return &s, nil
 }
 

stats.go

@@ -6,6 +6,7 @@ import (
 	"log"
 	"net"
 	"net/http"
+	"net/http/pprof"
 	"runtime"
 	"strconv"
 	"time"
@@ -93,6 +94,8 @@ func startPrometheusStats(l *logrus.Logger, i time.Duration, c *config.C, buildV
 		return nil, fmt.Errorf("stats.path should not be empty")
 	}
 
+	enablePprof := c.GetBool("stats.pprof", false)
+
 	pr := prometheus.NewRegistry()
 	pClient := mp.NewPrometheusProvider(metrics.DefaultRegistry, namespace, subsystem, pr, i)
 	if !configTest {
@@ -119,6 +122,14 @@ func startPrometheusStats(l *logrus.Logger, i time.Duration, c *config.C, buildV
 		startFn = func() {
 			l.Infof("Prometheus stats listening on %s at %s", listen, path)
 			http.Handle(path, promhttp.HandlerFor(pr, promhttp.HandlerOpts{ErrorLog: l}))
+			if enablePprof {
+				l.Info("pprof endpoints enabled on stats listener")
+				http.HandleFunc("GET /debug/pprof/", pprof.Index)
+				http.HandleFunc("GET /debug/pprof/cmdline", pprof.Cmdline)
+				http.HandleFunc("GET /debug/pprof/profile", pprof.Profile)
+				http.HandleFunc("GET /debug/pprof/symbol", pprof.Symbol)
+				http.HandleFunc("GET /debug/pprof/trace", pprof.Trace)
+			}
 			log.Fatal(http.ListenAndServe(listen, nil))
 		}
 	}

udp/conn.go

@@ -16,7 +16,7 @@ type EncReader func(
 type Conn interface {
 	Rebind() error
 	LocalAddr() (netip.AddrPort, error)
-	ListenOut(r EncReader) error
+	ListenOut(r EncReader)
 	WriteTo(b []byte, addr netip.AddrPort) error
 	ReloadConfig(c *config.C)
 	SupportsMultipleReaders() bool
@@ -31,8 +31,8 @@ func (NoopConn) Rebind() error {
 func (NoopConn) LocalAddr() (netip.AddrPort, error) {
 	return netip.AddrPort{}, nil
 }
-func (NoopConn) ListenOut(_ EncReader) error {
+func (NoopConn) ListenOut(_ EncReader) {
-	return nil
+	return
 }
 func (NoopConn) SupportsMultipleReaders() bool {
 	return false

udp/udp_darwin.go

@@ -165,7 +165,7 @@ func NewUDPStatsEmitter(udpConns []Conn) func() {
 	return func() {}
 }
 
-func (u *StdConn) ListenOut(r EncReader) error {
+func (u *StdConn) ListenOut(r EncReader) {
 	buffer := make([]byte, MTU)
 
 	for {
@@ -173,7 +173,8 @@ func (u *StdConn) ListenOut(r EncReader) error {
 		n, rua, err := u.ReadFromUDPAddrPort(buffer)
 		if err != nil {
 			if errors.Is(err, net.ErrClosed) {
-				return err
+				u.l.WithError(err).Debug("udp socket is closed, exiting read loop")
+				return
 			}
 
 			u.l.WithError(err).Error("unexpected udp socket receive error")

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"
@@ -71,14 +73,25 @@ type rawMessage struct {
 	Len uint32
 }
 
-func (u *GenericConn) ListenOut(r EncReader) error {
+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 {
-			return err
+			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_linux.go

@@ -9,7 +9,6 @@ import (
 	"net"
 	"net/netip"
 	"syscall"
-	"time"
 	"unsafe"
 
 	"github.com/rcrowley/go-metrics"
@@ -18,8 +17,6 @@ import (
 	"golang.org/x/sys/unix"
 )
 
-var readTimeout = unix.NsecToTimeval(int64(3 * time.Second))
-
 type StdConn struct {
 	sysFd int
 	isV4  bool
@@ -27,6 +24,14 @@ type StdConn struct {
 	batch int
 }
 
+func maybeIPV4(ip net.IP) (net.IP, bool) {
+	ip4 := ip.To4()
+	if ip4 != nil {
+		return ip4, true
+	}
+	return ip, false
+}
+
 func NewListener(l *logrus.Logger, ip netip.Addr, port int, multi bool, batch int) (Conn, error) {
 	af := unix.AF_INET6
 	if ip.Is4() {
@@ -50,11 +55,6 @@ func NewListener(l *logrus.Logger, ip netip.Addr, port int, multi bool, batch in
 		}
 	}
 
-	// Set a read timeout
-	if err = unix.SetsockoptTimeval(fd, unix.SOL_SOCKET, unix.SO_RCVTIMEO, &readTimeout); err != nil {
-		return nil, fmt.Errorf("unable to set SO_RCVTIMEO: %s", err)
-	}
-
 	var sa unix.Sockaddr
 	if ip.Is4() {
 		sa4 := &unix.SockaddrInet4{Port: port}
@@ -122,7 +122,7 @@ func (u *StdConn) LocalAddr() (netip.AddrPort, error) {
 	}
 }
 
-func (u *StdConn) ListenOut(r EncReader) error {
+func (u *StdConn) ListenOut(r EncReader) {
 	var ip netip.Addr
 
 	msgs, buffers, names := u.PrepareRawMessages(u.batch)
@@ -134,7 +134,8 @@ func (u *StdConn) ListenOut(r EncReader) error {
 	for {
 		n, err := read(msgs)
 		if err != nil {
-			return err
+			u.l.WithError(err).Debug("udp socket is closed, exiting read loop")
+			return
 		}
 
 		for i := 0; i < n; i++ {
@@ -162,9 +163,6 @@ func (u *StdConn) ReadSingle(msgs []rawMessage) (int, error) {
 		)
 
 		if err != 0 {
-			if err == unix.EAGAIN || err == unix.EINTR || err == unix.EWOULDBLOCK {
-				continue
-			}
 			return 0, &net.OpError{Op: "recvmsg", Err: err}
 		}
 
@@ -184,14 +182,8 @@ func (u *StdConn) ReadMulti(msgs []rawMessage) (int, error) {
 			0,
 			0,
 		)
-		if err == unix.EAGAIN || err == unix.EINTR || err == unix.EWOULDBLOCK {
+
-			if int64(n) > 0 {
+		if err != 0 {
-				//ran out of time, but have some messages to return
-				return int(n), nil
-			} else {
-				continue
-			}
-		} else if err != 0 {
 			return 0, &net.OpError{Op: "recvmmsg", Err: err}
 		}
 

udp/udp_rio_windows.go

@@ -140,7 +140,7 @@ func (u *RIOConn) bind(l *logrus.Logger, sa windows.Sockaddr) error {
 	return nil
 }
 
-func (u *RIOConn) ListenOut(r EncReader) error {
+func (u *RIOConn) ListenOut(r EncReader) {
 	buffer := make([]byte, MTU)
 
 	var lastRecvErr time.Time
@@ -151,7 +151,8 @@ func (u *RIOConn) ListenOut(r EncReader) error {
 
 		if err != nil {
 			if errors.Is(err, net.ErrClosed) {
-				return err
+				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 {

udp/udp_tester.go

@@ -6,7 +6,6 @@ package udp
 import (
 	"io"
 	"net/netip"
-	"os"
 	"sync/atomic"
 
 	"github.com/sirupsen/logrus"
@@ -107,11 +106,11 @@ func (u *TesterConn) WriteTo(b []byte, addr netip.AddrPort) error {
 	return nil
 }
 
-func (u *TesterConn) ListenOut(r EncReader) error {
+func (u *TesterConn) ListenOut(r EncReader) {
 	for {
 		p, ok := <-u.RxPackets
 		if !ok {
-			return os.ErrClosed
+			return
 		}
 		r(p.From, p.Data)
 	}