cbb
79633a2b0f
后端 PDO 循环改为按在线槽收缩状态窗口，稀疏总线下单槽每周期都能刷新， 并补上尾部槽的发现扫描游标；新增自旋节拍源（阈值/显式覆盖）、P 核识别 与线程级钉核，自旋期间释放 GIL 以免 HTTP 线程被饿死；启动时先关停旧实例， 避免两个进程争用 Npcap 适配器。 记录每拍完整时间线、GC stop-the-world 事件与网格跳拍数，经 /api/motor/dbg 导出用于归因固定频率的超时；配
142 lines
5.9 KiB
Python
142 lines
5.9 KiB
Python
#!/usr/bin/env python3
|
||
"""归因"某一拍为什么超时"：把 PDO 时间线与 GC / HTTP 事件时间线做交集。
|
||
|
||
背景：250us 和 200us 档的达成率都是 96~97%，几乎不随档位变化 —— 丢拍不像
|
||
"总线差几十 us"这种比例性原因，更像固定频率的事件(GC 停止世界、HTTP 线程
|
||
持 GIL 序列化快照、系统杂活)一撞就是一整个时隙。本脚本从 /api/motor/dbg
|
||
拉三条原始时间线，对每一个超时拍给出责任归属。
|
||
|
||
用法(目标服务必须已在跑，本脚本自己不会拉服务)：
|
||
python cadence_diag.py --period 0.25 --sample 6
|
||
python cadence_diag.py --period 0.2 --gc off # A/B：关掉 GC 看超时拍是否消失
|
||
python cadence_diag.py --period 0.2 --gc on --hammer 2 # 再叠 2 路 /motor/state 轮询
|
||
|
||
判读：
|
||
超时拍 = loop_end-t0(work) 超过设定周期的拍；它们正是网格跳掉的拍。
|
||
归因窗口 = 上一拍 loop_end → 本拍 loop_end；GC/HTTP 事件落在窗口内即认领。
|
||
"裸超时"占大头才说明是内核/中断层面的抢占，而不是进程内流程问题。
|
||
"""
|
||
import argparse
|
||
import json
|
||
import statistics
|
||
import threading
|
||
import time
|
||
import urllib.request
|
||
|
||
BASE_DEFAULT = "http://127.0.0.1:8090"
|
||
|
||
|
||
def api(base, path, req):
|
||
r = urllib.request.Request(base + "/api/" + path,
|
||
data=json.dumps(req).encode(),
|
||
headers={"Content-Type": "application/json"})
|
||
with urllib.request.urlopen(r, timeout=30) as resp:
|
||
return json.loads(resp.read().decode())
|
||
|
||
|
||
def hammer_worker(base, stop, path="motor/state"):
|
||
while not stop.is_set():
|
||
try:
|
||
api(base, path, {})
|
||
except Exception:
|
||
pass
|
||
|
||
|
||
def classify(beats, gc_ev, http_ev, period_us):
|
||
"""给每个超时拍贴标签。返回 (late列表, 计数统计)。beats: 按 t0 排序的样本。"""
|
||
counts = {"GC": 0, "HTTP": 0, "GC+HTTP": 0, "裸超时": 0}
|
||
late = []
|
||
for i in range(1, len(beats)):
|
||
t0, ts, tm, tr, te, k = beats[i]
|
||
work = (te - t0) * 1e6
|
||
if work <= period_us:
|
||
continue
|
||
w0, w1 = beats[i - 1][4], te # 上一拍结束 → 本拍结束
|
||
g = [e for e in gc_ev if w0 <= e[0] <= w1 and e[1] > 20.0]
|
||
h = [x for x in http_ev if x[0] < w1 and x[1] > w0 and (x[1] - x[0]) * 1e6 > 20.0]
|
||
if g and h:
|
||
tag = "GC+HTTP"
|
||
elif g:
|
||
tag = "GC(gen%d %.0fus)" % (g[-1][2], g[-1][1])
|
||
counts["GC"] += 1
|
||
elif h:
|
||
tag = "HTTP(%s %.0fus)" % (h[-1][2].replace("/api/", ""), (h[-1][1] - h[-1][0]) * 1e6)
|
||
counts["HTTP"] += 1
|
||
else:
|
||
tag = "裸超时"
|
||
counts["裸超时"] += 1
|
||
if g and h:
|
||
counts["GC+HTTP"] += 1
|
||
late.append((work, k, tag, (t0 - beats[i - 1][4]) * 1e6))
|
||
return late, counts
|
||
|
||
|
||
def main():
|
||
ap = argparse.ArgumentParser()
|
||
ap.add_argument("--base", default=BASE_DEFAULT)
|
||
ap.add_argument("--period", type=float, required=True, help="周期 ms(0.25=250us)")
|
||
ap.add_argument("--sample", type=float, default=6.0, help="设周期后预热秒数，之后才取窗口")
|
||
ap.add_argument("--gc", choices=["on", "off", "keep"], default="keep")
|
||
ap.add_argument("--hammer", type=int, default=0, help="叠加 N 路 /motor/state 轮询线程")
|
||
args = ap.parse_args()
|
||
per_us = args.period * 1000.0
|
||
|
||
if args.gc != "keep":
|
||
r = api(args.base, "motor/dbg", {"action": "gc", "enable": args.gc == "on"})
|
||
print(f"GC → {r.get('gc_enabled')}")
|
||
|
||
r = api(args.base, "motor/period", {"period_ms": args.period})
|
||
print("period:", r.get("log"))
|
||
if r.get("spin") is False and args.period < 1:
|
||
print("!! 自旋没生效，这组数据没有意义")
|
||
return 1
|
||
|
||
stop = threading.Event()
|
||
threads = [threading.Thread(target=hammer_worker, args=(args.base, stop), daemon=True)
|
||
for _ in range(args.hammer)]
|
||
for t in threads:
|
||
t.start()
|
||
try:
|
||
time.sleep(args.sample)
|
||
d = api(args.base, "motor/dbg", {})
|
||
finally:
|
||
stop.set()
|
||
for t in threads:
|
||
t.join(timeout=1)
|
||
|
||
beats = sorted(d["cyc"])[:-50] # 尾部几十拍被 dump 自身的 GIL 占用污染，丢弃
|
||
if len(beats) < 100:
|
||
print("样本不足", len(beats))
|
||
return 1
|
||
iv = [(beats[i][0] - beats[i - 1][0]) * 1e6 for i in range(1, len(beats))]
|
||
hz = 1e6 / statistics.fmean(iv)
|
||
work = sorted((e - t) * 1e6 for t, _, _, _, e, _ in beats)
|
||
print(f"\n窗口 {len(beats)} 拍 ≈ {sum(iv) / 1e6:.2f}s | 周期 {per_us:.0f}us | "
|
||
f"实测 {hz:.0f}Hz (达成 {hz / (1e6 / per_us) * 100:.1f}%) | "
|
||
f"跳拍合计 {sum(k for *_, k in beats)}")
|
||
gc_in_win = [e[2] for e in d["gc_events"] if beats[0][0] <= e[0] <= beats[-1][4]]
|
||
print(f"work p50/p90/max = {work[len(work) // 2]:.0f}/{work[int(len(work) * .9)]:.0f}/"
|
||
f"{work[-1]:.0f}us | 窗口内 GC g0/g1/g2 = "
|
||
f"{gc_in_win.count(0)}/{gc_in_win.count(1)}/{gc_in_win.count(2)}")
|
||
|
||
# 事件按窗口时间过滤，再交集
|
||
w0, w1 = beats[0][0], beats[-1][4]
|
||
gc_ev = [e for e in d["gc_events"] if w0 <= e[0] <= w1]
|
||
http_ev = [x for x in d["http"] if x[1] >= w0 and x[0] <= w1]
|
||
late, counts = classify(beats, gc_ev, http_ev, per_us)
|
||
n_late = len(late)
|
||
print(f"超时拍 {n_late}/{len(beats)} = {n_late / len(beats) * 100:.2f}% | "
|
||
+ " | ".join(f"{k}: {v}" for k, v in counts.items()))
|
||
if late:
|
||
lateness = sorted(x[0] for x in late)
|
||
print(f"超时拍的 work: 中位 {statistics.median(lateness):.0f}us, "
|
||
f"p90 {lateness[int(len(lateness) * .9)]:.0f}us, max {lateness[-1]:.0f}us")
|
||
print("最狠的 8 拍:")
|
||
for work_us, k, tag, gap in sorted(late, reverse=True)[:8]:
|
||
print(f" work={work_us:7.0f}us 跳{k}拍 上游空闲{gap:6.0f}us {tag}")
|
||
return 0
|
||
|
||
|
||
if __name__ == "__main__":
|
||
raise SystemExit(main())
|