Files
ykxmz/_build/diag_relay_bench.py
T
xmz7891 cc5891e6d0 修局域网/中转对比基准:它自己有两个 bug,害产品背了黑锅
这个基准一直是红的(中转那条路报「连接阶段失败: timed out」),
而且报告里写着"这是中转链路的产品 bug"。**查下来不是产品的问题。**

== bug 1:两条路用了同一个配对码 ==

基准为了排除互相干扰,给两条路**各起一台全新被控端**(设计是对的),
但两台都用了写死的 code="246813"。

中转有「一个配对码只属于一台设备」的规则:
  第 1 台(跑局域网)注册成功
    -> stop_agent 杀掉进程,但**中转还以为它在线**(last_seen 没过期)
  第 2 台(跑中转)用同一个码注册 -> **被拒**
     中转日志:配对码 246813 已被 ... 占用,拒绝 ...
  而 start_agent 只检查"有没有设备在线" —— 第 1 台僵尸还挂着,
  于是**以为新的一台登记成功了**
  -> 没有任何进程在回包 -> 超时

对照实验(新增 _build/verify_code_reuse.py):
  场景 A 同一个码   -> **不通**
  场景 B 各用不同码 -> 通

修法:两条路各用不同码;start_agent 的判据从"有没有在线设备"
      改成"有没有**配对码正好是这一台要用的码**的在线设备"。

== bug 2:attach 用的还是旧码(我第一版补丁也漏了这处)==

relay_connect() 里 `client.attach(code)` 用的还是局域网那个码 ——
attach 到一台已经死掉、但中转以为在线的设备上,pair 自然没人回。

修成 `attach(relay_code)`。

== 顺带更新一段过时注释 ==

原文写着「当前版本经中转只稳定支撑前 1~2 次交互……这是中转链路的
产品 bug」,并据此把中转的轮数调小、超时调短。

那个 bug **已经修好了**(根因:一条 HTTP/1.1 连接被长轮询和发命令
两个线程同时用,撞状态机抛 CannotSendRequest("Idle"),
异常冒到 _client_loop 外面把 client-relay 线程打死)。
注释不更新会误导后人以为产品还有这个问题。

== 修好之后的实测(本地中转,30 次/路)==

    局域网  握手 16ms  成功 30/30 (100%)  中位  0ms  P90  0ms  最大  1ms
    中转    握手 46ms  成功 30/30 (100%)  中位 15ms  P90 29ms  最大 32ms

这是本地中转,量的是**协议本身的开销**(长轮询往返 vs 直连 TCP);
真实跨网络那条腿的 1.0~1.5 秒来自隧道和 4G,是另一回事。

结论:局域网确实是"毫秒级、不耗流量"的那条根本路径 ——
中位 0ms vs 15ms,而且不走任何外网。

踩坑记录:这两处都是"看起来像产品 bug、实际是测试自己的 bug"。
先怀疑测量工具,比先怀疑产品更省时间 ——
上一次(管理页缓存头)也是我拿 curl -I 测 GET 白查了半天。
2026-10-07 18:20:57 +08:00

242 lines
9.1 KiB
Python
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# -*- coding: utf-8 -*-
r'''复刻 bench_lan_vs_relay 的中转那一半,抓被控端日志。
我自己那个 ins_relay_flow.py 是中转 4/4 通过的,
但 bench_lan_vs_relay.py 的中转那半报"连接阶段失败: timed out"。
差异一定在设置里,所以要逐项对齐 bench 的写法:
* RELAY_POLL=2(我那边是 5)
* 用 YKXMZ_DATA 指到临时目录 + --silent(我那边直接写 windows/data)
* 每条路起**一台全新的**被控端
* 先 attach 再 pair(bench 的 relay_connect 就是这么做的)
把每一步的耗时和被控端日志都打出来。
'''
from __future__ import annotations
import json
import os
import socket
import subprocess
import sys
import tempfile
import time
import urllib.error
import urllib.request
from pathlib import Path
ROOT = Path(__file__).resolve().parent.parent
WINDOWS = ROOT / "windows"
UA = {"User-Agent": "LanRemote/1.8.2"}
CODE = "975310"
def free_port() -> int:
s = socket.socket()
s.bind(("127.0.0.1", 0))
p = s.getsockname()[1]
s.close()
return p
def post(base, path, body=b"", headers=None, timeout=20.0):
h = dict(UA)
h.update(headers or {})
req = urllib.request.Request(base + path, data=body, headers=h,
method="POST")
try:
with urllib.request.urlopen(req, timeout=timeout) as resp:
return resp.status, resp.read()
except urllib.error.HTTPError as exc:
return exc.code, exc.read()
except Exception as exc: # noqa: BLE001
return 0, str(exc).encode()
def get(base, path, timeout=5.0):
req = urllib.request.Request(base + path, headers=UA)
try:
with urllib.request.urlopen(req, timeout=timeout) as resp:
return resp.status, resp.read()
except Exception as exc: # noqa: BLE001
return 0, str(exc).encode()
def main() -> int:
work = Path(tempfile.mkdtemp(prefix="benchdiag_"))
relay_port = free_port()
agent_port = free_port()
base = "http://127.0.0.1:%d" % relay_port
relay_proc = agent_proc = None
relay_log = agent_log = None
try:
print(" 中转端口 %d 被控端端口 %d" % (relay_port, agent_port))
# ---- 1. 本地中转(对齐 bench:RELAY_POLL=2)----
rdata = work / "r"
rdata.mkdir(parents=True, exist_ok=True)
env = dict(os.environ)
env.update({"RELAY_PORT": str(relay_port), "RELAY_BIND": "127.0.0.1",
"RELAY_DATA": str(rdata), "RELAY_POLL": "2",
"PYTHONIOENCODING": "utf-8", "PYTHONUNBUFFERED": "1"})
relay_log = open(work / "relay.log", "wb")
relay_proc = subprocess.Popen(
[sys.executable, "-u", str(ROOT / "relay" / "relay.py")], env=env,
stdout=relay_log, stderr=subprocess.STDOUT)
for _ in range(60):
time.sleep(0.5)
if get(base, "/v1/health")[0] == 200:
break
print(" 中转就绪")
# ---- 2. 被控端(对齐 bench:YKXMZ_DATA + --silent + 独立锁端口)----
sys.path.insert(0, str(WINDOWS))
from lanremote.config import Store
adata = work / "a"
adata.mkdir(parents=True, exist_ok=True)
store = Store(adata)
store.set_pairing_code(CODE)
store.set("setup_done", True)
store.set("allow_new_pairing", True)
store.set("close_pair_after_first", False)
store.set("server_name", "基准测试电脑")
store.set("relay_url", base)
store.set("port", agent_port)
aenv = dict(os.environ)
aenv.update({"YKXMZ_DATA": str(adata),
"YKXMZ_LOCK_PORT": str(free_port()),
"PYTHONIOENCODING": "utf-8", "PYTHONUNBUFFERED": "1"})
agent_log = open(work / "agent.log", "wb")
agent_proc = subprocess.Popen(
[sys.executable, "-u", str(WINDOWS / "run_agent.py"),
"--silent", "--port", str(agent_port)],
cwd=str(WINDOWS), env=aenv,
stdout=agent_log, stderr=subprocess.STDOUT)
online = False
for _ in range(45):
time.sleep(1.0)
if agent_proc.poll() is not None:
print(" ✗ 被控端启动即退出,返回码 %s" % agent_proc.returncode)
break
st, body = get(base, "/v1/health", timeout=4)
if st == 200:
snap = json.loads(body.decode())
if any(d.get("online") for d in snap.get("devices", [])):
online = True
break
print(" 被控端登记: %s" % ("成功" if online else "**失败**"))
if not online:
return 1
# ---- 3. 完全照 bench 的 relay_connect 做 ----
print()
print(" ── 照 bench 的顺序:attach -> pair ──")
t0 = time.time()
st, body = post(base, "/v1/client/attach", json.dumps(
{"code": CODE, "name": "基准测试手表"}).encode(),
{"Content-Type": "application/json"})
att = json.loads(body.decode())
session = att.get("session", "")
print(" attach: %dms ok=%s session=%s"
% (int((time.time() - t0) * 1000), att.get("ok"),
session[:8] if session else "无"))
payload = (json.dumps({"cmd": "pair", "deviceId": "bench-relay",
"deviceName": "基准测试手表",
"code": CODE}, ensure_ascii=False)
+ "\n").encode()
t0 = time.time()
st, _ = post(base, "/v1/client/send", payload, {"X-Session": session})
print(" send pair: %dms status=%s" % (int((time.time() - t0) * 1000), st))
# 轮询等回复,每轮都打点
buf = b""
deadline = time.time() + 40
got = None
round_no = 0
while time.time() < deadline:
round_no += 1
remaining = deadline - time.time()
t0 = time.time()
st, chunk = post(base, "/v1/client/poll", b"",
{"X-Session": session}, min(10.0, remaining))
buf += chunk
print(" poll#%d: %dms status=%s 收到 %d 字节"
% (round_no, int((time.time() - t0) * 1000), st, len(chunk)))
while b"\n" in buf:
line, _, buf = buf.partition(b"\n")
if not line.strip():
continue
msg = json.loads(line.decode())
if "event" in msg:
continue
got = msg
break
if got is not None:
break
if got is None:
print(" ✗ 40 秒内没等到 pair 的回复")
else:
print(" ✓ pair 回复: %s" % json.dumps(got, ensure_ascii=False)[:120])
# ---- 4. 再来几次 ping ----
if got is not None:
for i in range(5):
payload = (json.dumps({"cmd": "ping"}) + "\n").encode()
post(base, "/v1/client/send", payload, {"X-Session": session})
deadline = time.time() + 15
ok = False
while time.time() < deadline:
st, chunk = post(base, "/v1/client/poll", b"",
{"X-Session": session}, 8.0)
buf += chunk
while b"\n" in buf:
line, _, buf = buf.partition(b"\n")
if not line.strip():
continue
msg = json.loads(line.decode())
if "event" in msg:
continue
ok = True
break
if ok:
break
print(" ping#%d: %s" % (i + 1, "OK" if ok else "**超时**"))
# ---- 5. 被控端日志 ----
print()
print(" ════ 被控端日志(最后 25 行)════")
agent_log.flush()
for line in (work / "agent.log").read_text(
encoding="utf-8", errors="replace").splitlines()[-25:]:
print(" " + line[:120])
print()
print(" ════ 进程还活着吗 ════")
print(" agent poll = %s" % agent_proc.poll())
print()
print(" ════ 中转日志(最后 10 行)════")
relay_log.flush()
for line in (work / "relay.log").read_text(
encoding="utf-8", errors="replace").splitlines()[-10:]:
print(" " + line[:120])
return 0
finally:
for p in (agent_proc, relay_proc):
if p is not None:
try:
p.terminate()
p.wait(timeout=6)
except Exception: # noqa: BLE001
try:
p.kill()
except Exception: # noqa: BLE001
pass
import shutil
shutil.rmtree(work, ignore_errors=True)
if __name__ == "__main__":
sys.exit(main())