guest-diag: non-blocking trace tail + 100ms scan loop + raw counter-page dump

- the trace tail (subprocess + 256KB read) ran inside the scan loop and
  blocked it for seconds exactly when the client's GR window appeared;
  moved to a background thread whose queue the loop drains.
- scan interval 250ms -> 100ms.
- track_waits sampler also dumps 512 raw bytes at page+0xe00 each sample:
  the per-slot reads disagreed with the bulk dump within one sample
  because host writes land between the two, and the raw dump is the only
  trustworthy view of the slot layout.

2 files changed, 55 insertions, 4 deletions

diff --git a/tools/guest-diag/guest_pin_stream.py b/tools/guest-diag/guest_pin_stream.py
index 717a05d..bed4728 100644
--- a/tools/guest-diag/guest_pin_stream.py
+++ b/tools/guest-diag/guest_pin_stream.py
@@ -15,6 +15,7 @@ import re
 import socket
 import subprocess
 import sys
+import threading
 import time
 
 CID = int(sys.argv[1]) if len(sys.argv) > 1 else 2
@@ -22,7 +23,7 @@ PORT = int(sys.argv[2]) if len(sys.argv) > 2 else 45678
 LO = int(sys.argv[3], 16) if len(sys.argv) > 3 else 0x200400000
 HI = int(sys.argv[4], 16) if len(sys.argv) > 4 else 0x206000000
 PAMAX = int(sys.argv[5], 16) if len(sys.argv) > 5 else 0x180000000
-INTERVAL = float(os.environ.get("STREAM_INTERVAL", "0.25"))
+INTERVAL = float(os.environ.get("STREAM_INTERVAL", "0.1"))
 BATCH = 4096
 REGION = 0x200000
 # The GR GPFIFO rings sit at 0x20020c000 + 0x3000*rank (region offset 0xc000
@@ -35,6 +36,45 @@ TRACE = ("/sys/kernel/tracing/trace"
 SEM_EVERY = int(os.environ.get("STREAM_SEM_EVERY", "4"))
 
 
+class TraceReader:
+    """Tail the guest trace for new uvmt semaphore kptrs in a thread.
+
+    Reading the trace can block for seconds under client load; doing it in
+    the scan loop delayed the first GR-window delta (observed a 3 s gap
+    right when the client's channels appeared). The thread appends to a
+    queue the main loop drains without blocking.
+    """
+
+    def __init__(self):
+        self.sems = []
+        self.seen = set()
+        self.lock = threading.Lock()
+        self.stop = False
+        self.t = threading.Thread(target=self._run, daemon=True)
+        self.t.start()
+
+    def _run(self):
+        while not self.stop:
+            try:
+                out = subprocess.run(["tail", "-c", "262144", TRACE],
+                                     capture_output=True, timeout=10).stdout
+            except Exception:
+                time.sleep(1)
+                continue
+            with self.lock:
+                for m in re.finditer(rb"sem=0x([0-9a-fA-F]+)", out):
+                    v = int(m.group(1), 16)
+                    if v not in self.seen:
+                        self.seen.add(v)
+                        self.sems.append(v)
+            time.sleep(0.5)
+
+    def drain(self):
+        with self.lock:
+            out, self.sems = self.sems, []
+        return out
+
+
 def new_sems(seen):
     """New tracking-sem kptrs (uvmt lines) in the trace tail.
 
@@ -112,6 +152,7 @@ def main():
     sock = None
     seen = {}
     seen_sems = set()
+    tracer = TraceReader()
     last_pid = None
     last_log = 0.0
     loop = 0
@@ -164,9 +205,9 @@ def main():
         new = [(va, pa) for va, pa in cur.items() if seen.get(va) != pa]
         seen = cur
         lines = []
-        if loop % SEM_EVERY == 0:
-            for sem in new_sems(seen_sems):
-                lines.append('#sem 0x%x\n' % sem)
+        for sem in tracer.drain():
+            seen_sems.add(sem)
+            lines.append('#sem 0x%x\n' % sem)
         now = time.time()
         if now - last_log > 1.0:
             last_log = now
diff --git a/tools/guest-diag/track_waits.sh b/tools/guest-diag/track_waits.sh
index 6ae9154..1e3cc91 100644
--- a/tools/guest-diag/track_waits.sh
+++ b/tools/guest-diag/track_waits.sh
@@ -45,6 +45,16 @@ while True:
         except OSError:
             vals.append('%d:ERR' % i)
     print('%s %s' % (ts, ' '.join(vals)), flush=True)
+    # Raw hex dump of the counter window: shows the true slot layout and any
+    # value a stride-16 sample would misread.
+    try:
+        os.lseek(pm, (page // 4096) * 8, 0)
+        e = int.from_bytes(os.read(pm, 8), 'little')
+        if (e >> 63) & 1:
+            raw = os.pread(mem, 0x200, page + 0xe00)
+            print('%s RAW %s' % (ts, raw.hex()), flush=True)
+    except OSError:
+        pass
     time.sleep(0.5)
 PY
 CNTPID=$!