succd: run at 100Hz, monitor load and jitter

succbone/succd/process.go

@@ -5,6 +5,7 @@ import (
 	"errors"
 	"fmt"
 	"sync"
+	"sync/atomic"
 	"time"
 
 	"k8s.io/klog"
@@ -23,6 +24,8 @@ type daemon struct {
 	gpioBelowRough    gpio
 	gpioBelowHigh     gpio
 
+	load atomic.Int64
+
 	// mu guards the state below.
 	mu sync.RWMutex
 	daemonState
@@ -62,11 +65,22 @@ func (d *daemonState) vacuumStatus() (rough, high bool) {
 
 // process runs the pain acquisition and control loop of succd.
 func (d *daemon) process(ctx context.Context) {
-	ticker := time.NewTicker(time.Millisecond * 100)
+	var lastRun time.Time
+	hz := 100
+	period := time.Second / time.Duration(hz)
+	// Extra grace period for GC pauses and other non-realtime system jitter.
+	periodGrace := period + time.Millisecond*5
+
+	ticker := time.NewTicker(period)
 	defer ticker.Stop()
 	for {
 		select {
 		case <-ticker.C:
+			now := time.Now()
+			if elapsed := now.Sub(lastRun); !lastRun.IsZero() && elapsed > periodGrace {
+				klog.Warningf("Processing loop lag: took %s, want %s", elapsed, period)
+			}
+			lastRun = now
 			if err := d.processOnce(ctx); err != nil {
 				if errors.Is(err, ctx.Err()) {
 					return
@@ -75,6 +89,9 @@ func (d *daemon) process(ctx context.Context) {
 					time.Sleep(time.Second * 10)
 				}
 			}
+			runtime := time.Since(lastRun)
+			load := int64(100 * runtime / period)
+			d.load.Store(load)
 		case <-ctx.Done():
 			return
 		}