improve debug logging, rw lock for notifier

Signed-off-by: Kristoffer Dalby <kristoffer@tailscale.com>

hscontrol/auth_noise.go

@@ -23,6 +23,7 @@ func (ns *noiseServer) NoiseRegistrationHandler(
 
 	log.Trace().
 		Any("headers", req.Header).
+		Caller().
 		Msg("Headers")
 
 	body, _ := io.ReadAll(req.Body)

hscontrol/notifier/notifier.go

@@ -9,7 +9,7 @@ import (
 )
 
 type Notifier struct {
-	l     sync.Mutex
+	l     sync.RWMutex
 	nodes map[string]chan<- types.StateUpdate
 }
 
@@ -18,6 +18,9 @@ func NewNotifier() *Notifier {
 }
 
 func (n *Notifier) AddNode(machineKey string, c chan<- types.StateUpdate) {
+	log.Trace().Caller().Str("key", machineKey).Msg("acquiring lock to add node")
+	defer log.Trace().Caller().Str("key", machineKey).Msg("releasing lock to add node")
+
 	n.l.Lock()
 	defer n.l.Unlock()
 
@@ -34,6 +37,9 @@ func (n *Notifier) AddNode(machineKey string, c chan<- types.StateUpdate) {
 }
 
 func (n *Notifier) RemoveNode(machineKey string) {
+	log.Trace().Caller().Str("key", machineKey).Msg("acquiring lock to remove node")
+	defer log.Trace().Caller().Str("key", machineKey).Msg("releasing lock to remove node")
+
 	n.l.Lock()
 	defer n.l.Unlock()
 
@@ -54,14 +60,21 @@ func (n *Notifier) NotifyAll(update types.StateUpdate) {
 }
 
 func (n *Notifier) NotifyWithIgnore(update types.StateUpdate, ignore ...string) {
-	n.l.Lock()
+	log.Trace().Caller().Interface("type", update.Type).Msg("acquiring lock to notify")
-	defer n.l.Unlock()
+	defer log.Trace().
+		Caller().
+		Interface("type", update.Type).
+		Msg("releasing lock, finished notifing")
+
+	n.l.RLock()
+	defer n.l.RUnlock()
 
 	for key, c := range n.nodes {
 		if util.IsStringInSlice(ignore, key) {
 			continue
 		}
 
+		log.Trace().Caller().Str("machine", key).Strs("ignoring", ignore).Msg("sending update")
 		c <- update
 	}
 }

hscontrol/poll_noise.go

@@ -31,6 +31,7 @@ func (ns *noiseServer) NoisePollNetMapHandler(
 
 	log.Trace().
 		Any("headers", req.Header).
+		Caller().
 		Msg("Headers")
 
 	body, _ := io.ReadAll(req.Body)