From 96e07ece2d8a8187e2d64af1e3b8ea9d4cf9c4eb Mon Sep 17 00:00:00 2001
From: Serge Bazanski <q3k@q3k.org>
Date: Sat, 28 Sep 2024 14:26:24 +0200
Subject: [PATCH] succd: run at 100Hz, monitor load and jitter

---
 succbone/succd/http.go               |  4 ++++
 succbone/succd/index.html            | 12 ++++++++----
 succbone/succd/process.go            | 19 ++++++++++++++++++-
 succbone/succd/process_controller.go |  5 +++++
 4 files changed, 35 insertions(+), 5 deletions(-)

diff --git a/succbone/succd/http.go b/succbone/succd/http.go
index 61df8a8..4365428 100644
--- a/succbone/succd/http.go
+++ b/succbone/succd/http.go
@@ -70,6 +70,9 @@ type apiData struct {
 		// HighReached is true when the system has reached a high vacuum stage.
 		HighReached bool
 	}
+	// LoopLoad is a percentage expressing how busy the processing loop is; 100
+	// is full utilization; >100 is lag.
+	LoopLoad int64
 	// System junk.
 	System struct {
 		// Load of the system.
@@ -114,6 +117,7 @@ func (s *webServer) apiData(skipSystem bool) *apiData {
 	ad.Pumps.DPOn = state.dpOn
 	ad.Feedback.RoughReached = rough
 	ad.Feedback.HighReached = high
+	ad.LoopLoad = s.d.loopLoad()
 	ad.System.Load = load
 	ad.System.Hostname = hostname
 	return &ad
diff --git a/succbone/succd/index.html b/succbone/succd/index.html
index 08acab3..a26db5d 100644
--- a/succbone/succd/index.html
+++ b/succbone/succd/index.html
@@ -100,27 +100,29 @@ td > span {
         <tr>
             <th rowspan="3">Control</th>
             <th>RP</th>
-            <td>
+            <td colspan="3">
                 <button id="rpon">On</button>
                 <button id="rpoff">Off</button>
             </td>
         </tr>
         <tr>
             <th>DP</th>
-            <td>
+            <td colspan="3">
                 <button id="dpon">On</button>
                 <button id="dpoff">Off</button>
             </td>
         </tr>
         <tr>
-            <td colspan="2">
+            <td colspan="3">
                 <button id="pd">Pump Down</button>
                 <button id="vent">Vent</button>
             </td>
         </tr>
         <tr>
             <th>Status</th>
-            <td id="status" colspan="4">OK</td>
+            <td id="status" colspan="1">OK</td>
+            <th>Load</th>
+            <td id="load" colspan="1">...</td>
         </tr>
     </table>
 </p>
@@ -275,6 +277,7 @@ window.addEventListener("load", (_) => {
     let ping = document.querySelector("#ping");
     let trough = document.querySelector("#trough");
     let thigh = document.querySelector("#thigh");
+    let load = document.querySelector("#load");
 
     // Buttons
     let pd = document.querySelector("#pd");
@@ -354,6 +357,7 @@ window.addEventListener("load", (_) => {
                 thigh.innerHTML = "NOK";
                 thigh.style = "background-color: #f06060";
             }
+            load.innerHTML = data.LoopLoad.toString() + "%";
             historicalPush(data.Pirani.MbarFloat);
             ping.innerHTML = Date.now();
         });
diff --git a/succbone/succd/process.go b/succbone/succd/process.go
index 026c13d..de99e84 100644
--- a/succbone/succd/process.go
+++ b/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
 		}
diff --git a/succbone/succd/process_controller.go b/succbone/succd/process_controller.go
index 0c0abc6..b7f689c 100644
--- a/succbone/succd/process_controller.go
+++ b/succbone/succd/process_controller.go
@@ -7,6 +7,7 @@ import "k8s.io/klog"
 //
 // This is a subset of daemon functions limited to a safe, explicit subset.
 type daemonController interface {
+	loopLoad() int64
 	// snapshot returns an internally consistent copy of the daemon state.
 	snapshot() *daemonState
 	// rpSet enables/disables the roughing pump.
@@ -19,6 +20,10 @@ type daemonController interface {
 	ventPress()
 }
 
+func (d *daemon) loopLoad() int64 {
+	return d.load.Load()
+}
+
 func (d *daemon) snapshot() *daemonState {
 	d.mu.RLock()
 	ds := d.daemonState