E-02审计闭环：timeSync分片修复留档（4a1605b台架A/B 28.6s→109ms）与E-02专项回归探针

2026-09-22 13:17:44 +08:00
parent 2643e936f5
commit 0cacdec598
2 changed files with 97 additions and 3 deletions
@@ -0,0 +1,90 @@
+#!/usr/bin/env python3
+"""E-02 头阻塞专项台架探针（timeSync 侧，A/B 对照用）。
+
+场景（错误码传播审计.md E-02 的 timeSync 触发形态）：
+  1. 一个"挂起"的对时客户端连上 :8888 后不发任何数据（空闲/故障客户端，
+     常见工况）——旧固件在此触发 30s 阻塞 net_recv 独占 netTask，
+     全体消费者的队列消息停摆最长 30s；
+  2. 2s 后从 PC 发起 FTP(:21) 连接，测 banner 到达时延 = 队列响应性：
+     修复前 ≈ 25~30s（队头冻结），修复后 ≈ 数百 ms 内；
+  3. 34s 时 30s 总预算应已耗尽：设备拆除该连接（修复版落
+     "time_sync: no TIME packet in 30s, drop conn" 日志，旧版静默）、
+     监听重建，:8888 应能再接受新连接；
+  4. 新连接发完整 8 字节 TIME 包 → 设备应落 "wall clock updated"。
+
+用法: python e02_probe.py <run-tag>
+退出码: 0 = 队列响应性 PASS；1 = FAIL；2 = 探针自身异常
+"""
+import socket
+import sys
+import time
+
+DEV = "192.168.1.100"
+tag = sys.argv[1] if len(sys.argv) > 1 else "run"
+
+t0 = time.time()
+
+
+def log(msg):
+    print("[%s] %9.3f %s" % (tag, time.time() - t0, msg), flush=True)
+
+
+def main():
+    # 1. 挂起对时客户端：连接后不发任何数据
+    ts = socket.create_connection((DEV, 8888), timeout=5)
+    log("time-sync conn open (hung client: sends nothing)")
+
+    # 2. 2s 后测 FTP banner 时延（队列响应性）
+    time.sleep(2.0)
+    t1 = time.time()
+    banner = None
+    try:
+        ftp = socket.create_connection((DEV, 21), timeout=35)
+        banner = ftp.recv(256)
+        dt = time.time() - t1
+        log("FTP banner after %8.1f ms: %r" % (dt * 1000, banner[:40]))
+        ftp.close()
+    except Exception as e:
+        dt = time.time() - t1
+        log("FTP connect FAIL after %8.1f ms: %r" % (dt * 1000, e))
+        dt = None
+    queue_ok = (banner is not None) and (dt is not None) and (dt < 3.0)
+    log("queue responsiveness: %s (banner %s ms)"
+        % ("PASS" if queue_ok else "FAIL",
+           ("%.0f" % (dt * 1000)) if dt is not None else "n/a"))
+
+    # 3. 等 30s 总预算耗尽（设备应拆除挂起连接、重建监听）
+    remain = 34.0 - (time.time() - t0)
+    if remain > 0:
+        time.sleep(remain)
+
+    # 4. 监听应已重建：新连接可接入，且正常对时路径工作
+    t2 = time.time()
+    listener_ok = False
+    try:
+        ts2 = socket.create_connection((DEV, 8888), timeout=5)
+        dt2 = time.time() - t2
+        epoch = int(time.time())
+        log("new time-sync conn in %6.0f ms, sent full TIME packet (epoch=%d)"
+            % (dt2 * 1000, epoch))
+        ts2.sendall(b"TIME" + epoch.to_bytes(4, "big"))
+        time.sleep(1.5)   # 留时间给设备处理并打日志
+        ts2.close()
+        listener_ok = True
+    except Exception as e:
+        log("second time-sync conn FAIL: %r" % (e,))
+    try:
+        ts.close()
+    except OSError:
+        pass   # 设备已先拆连，本地 close 报 ECONNRESET 属预期
+    log("OVERALL: queue=%s listener=%s"
+        % ("PASS" if queue_ok else "FAIL", "PASS" if listener_ok else "FAIL"))
+    return 0 if (queue_ok and listener_ok) else 1
+
+
+if __name__ == "__main__":
+    try:
+        sys.exit(main())
+    except Exception as e:
+        print("[%s] PROBE ERROR: %r" % (tag, e), flush=True)
+        sys.exit(2)