fix: report tran ssh runtime timing

docs/reference/cli.md

@@ -131,7 +131,7 @@ core 只允许声明了 `host.ssh` capability 的 provider 使用 `ssh` 透传
 
 本地 broker 默认等待 provider SSH 会话打开 60000ms，以便在目标节点同时有较多 microservice.http 任务时仍能建立维护会话；需要诊断慢连接时可用 `UNIDESK_SSH_OPEN_TIMEOUT_MS=<ms>` 临时调大，但最小有效值固定为 15000ms，避免把真实离线误判为长时间阻塞。
 
-ssh-like 远端命令如果出现 `kex_exchange_identification`、`Connection closed by remote host`、provider session timeout 或 exit code 255，CLI 会在原始 stderr 后追加一行 `UNIDESK_SSH_HINT { ... }`。该 JSON 不回显原始远端命令，只包含 `code=ssh-like-command-friction`、`trigger`、`try` 和 `triage`；`try` 固定指向 stdin script 形态，避免把一次 ssh-like 解析/握手摩擦误读成 D601 SSH 整体不可用。
+ssh-like 远端命令如果出现 `kex_exchange_identification`、`Connection closed by remote host`、provider session timeout 或 exit code 255，CLI 会在原始 stderr 后追加一行 `UNIDESK_SSH_HINT { ... }`。该 JSON 不回显原始远端命令，只包含 `code=ssh-like-command-friction`、`trigger`、`try` 和 `triage`；`try` 固定指向 stdin script 形态，避免把一次 ssh-like 解析/握手摩擦误读成 D601 SSH 整体不可用。每次 `ssh`/`tran` 运行结束还会在 stderr 追加一行 `UNIDESK_SSH_TIMING { ... }`，包含 `elapsedMs`、`elapsedSeconds`、`transport`、`invocationKind` 和 `exitCode`；耗时超过默认 10000ms 时 `level=warning`，提示优先排查 provider/session 延迟、远端命令自身耗时、helper bootstrap 或 `tran`/`apply-patch` 工具层回归。阈值可用 `UNIDESK_SSH_SLOW_WARNING_MS=<ms>` 临时调节，提示同样不回显原始远端命令。
 
 `ssh <providerId>` 只在当前 operation 需要 helper 时才注入 `/tmp/unidesk-ssh-tools`，普通 `argv`、`script`、`kubectl`、`logs` 等路径不得传输无关工具源码。`apply-patch` 只注入 `apply_patch`；`glob` 只注入 `glob`；`skills`/`skill discover` 只注入 `skill-discover`。`apply_patch` 接受标准 `*** Begin Patch` / `*** End Patch` patch 格式，便于通过 SSH 透传编辑远端仓库文件；远端存在 `perl` 时必须走快速精确匹配路径，避免大文件 hunk 被 sh 模式匹配拖成几十秒，缺少 `perl` 时才退回 sh-only 实现。`glob` 和 `skill-discover` 需要远端 `python3`。注入工具只写 `/tmp/unidesk-ssh-tools`，不修改目标仓库。
 

scripts/src/help.ts

@@ -177,6 +177,7 @@ export function sshHelp(): unknown {
       "Do not put operation names in any colon route segment, including nested k3s namespace/workload/container segments.",
       "Do not use post-provider shorthand such as `ssh G14 k3s ...`; write `ssh G14:k3s ...` so location and operation stay separated.",
       "If an ssh-like remote command fails with timeout/kex/exit-255 friction, stderr includes one low-noise UNIDESK_SSH_HINT JSON line with the argv retry command.",
+      "Every ssh/tran runtime writes one UNIDESK_SSH_TIMING JSON line to stderr with elapsedMs/elapsedSeconds; operations over 10s are marked level=warning and should be checked for provider latency, remote command cost, helper bootstrap, or tran/apply-patch optimization before repeating high-frequency work.",
       "Use -- before a remote command that intentionally starts with a dash.",
     ],
   };

scripts/src/remote.ts

@@ -6,7 +6,7 @@ import { type UniDeskConfig } from "./config";
 import { type DebugDispatchCommand, isDebugDispatchCommand } from "./debug";
 import { summarizeMicroserviceHealthResponse, summarizeMicroserviceObservation, summarizeMicroserviceProxyResponse } from "./microservices";
 import { parseNetworkPerfOptions, runNetworkPerf } from "./network-perf";
-import { formatSshFailureHint, parseSshInvocation, sshFailureHint, wrapSshRemoteCommand } from "./ssh";
+import { formatSshFailureHint, formatSshRuntimeTimingHint, parseSshInvocation, sshFailureHint, sshRuntimeTimingHint, wrapSshRemoteCommand } from "./ssh";
 import { codexJudgeQueryAsync, codexOutputQueryAsync, codexPrPreflightQueryAsync, codexQueuesQueryAsync, codexTaskQueryAsync, codexTasksQueryAsync, codexUnreadTriageAsync } from "./code-queue";
 import { runDecisionCenterCommandAsync } from "./decision-center";
 import {
@@ -888,6 +888,7 @@ async function runRemoteSshWebSocket(
   invocation: ReturnType<typeof parseSshInvocation>,
 ): Promise<number> {
   const parsed = invocation.parsed;
+  const startedAtMs = Date.now();
   const size = {
     cols: Number(process.stdout.columns) > 0 ? Number(process.stdout.columns) : 100,
     rows: Number(process.stdout.rows) > 0 ? Number(process.stdout.rows) : 30,
@@ -963,6 +964,12 @@ async function runRemoteSshWebSocket(
       restore();
       const hint = sshFailureHint(invocation.providerId, parsed, code, "");
       if (hint !== null) process.stderr.write(formatSshFailureHint(hint));
+      process.stderr.write(formatSshRuntimeTimingHint(sshRuntimeTimingHint({
+        invocation,
+        transport: "frontend-websocket",
+        exitCode: code,
+        startedAtMs,
+      })));
       resolve(code);
     };
     const onStdinData = (chunk: Buffer): void => {

scripts/src/ssh.ts

@@ -41,8 +41,25 @@ export interface SshFailureHint {
   note: string;
 }
 
+export interface SshRuntimeTimingHint {
+  code: "ssh-runtime-timing";
+  level: "info" | "warning";
+  providerId: string;
+  route: string;
+  transport: "backend-core-broker" | "frontend-websocket";
+  invocationKind: SshInvocationKind;
+  exitCode: number;
+  elapsedMs: number;
+  elapsedSeconds: number;
+  thresholdMs: number;
+  slow: boolean;
+  message: string;
+  note: string;
+}
+
 const argvQuotedSshSubcommands = new Set(["git", "rg", "grep", "sed", "nl", "stat", "du", "ls", "cat", "head", "tail", "wc", "pwd"]);
 const nativeK3sKubeconfig = "/etc/rancher/k3s/k3s.yaml";
+const defaultSshSlowWarningMs = 10_000;
 const k3sResourceKindAliases = new Set(["pod", "po", "pods", "deployment", "deploy", "deployments", "statefulset", "sts", "daemonset", "ds", "job", "jobs"]);
 const legacyK3sOperationRouteSegments = new Set([
   "guard",
@@ -1556,6 +1573,50 @@ export function formatSshFailureHint(hint: SshFailureHint): string {
   return `UNIDESK_SSH_HINT ${JSON.stringify(hint)}\n`;
 }
 
+export function sshSlowWarningThresholdMs(env: NodeJS.ProcessEnv = process.env): number {
+  const raw = env.UNIDESK_SSH_SLOW_WARNING_MS;
+  const parsed = raw === undefined ? NaN : Number(raw);
+  if (!Number.isFinite(parsed) || parsed <= 0) return defaultSshSlowWarningMs;
+  return Math.max(1000, Math.trunc(parsed));
+}
+
+export function sshRuntimeTimingHint(options: {
+  invocation: ParsedSshInvocation;
+  transport: SshRuntimeTimingHint["transport"];
+  exitCode: number;
+  startedAtMs: number;
+  finishedAtMs?: number;
+  thresholdMs?: number;
+}): SshRuntimeTimingHint {
+  const finishedAtMs = options.finishedAtMs ?? Date.now();
+  const thresholdMs = options.thresholdMs ?? sshSlowWarningThresholdMs();
+  const elapsedMs = Math.max(0, Math.round(finishedAtMs - options.startedAtMs));
+  const elapsedSeconds = Number((elapsedMs / 1000).toFixed(3));
+  const slow = elapsedMs > thresholdMs;
+  const thresholdSeconds = Number((thresholdMs / 1000).toFixed(3));
+  return {
+    code: "ssh-runtime-timing",
+    level: slow ? "warning" : "info",
+    providerId: safeProviderId(options.invocation.providerId),
+    route: options.invocation.route.raw,
+    transport: options.transport,
+    invocationKind: options.invocation.parsed.invocationKind,
+    exitCode: options.exitCode,
+    elapsedMs,
+    elapsedSeconds,
+    thresholdMs,
+    slow,
+    message: slow
+      ? `ssh operation took ${elapsedSeconds}s, above the ${thresholdSeconds}s warning threshold; consider checking provider/session latency, remote command cost, helper bootstrap, or tran/apply-patch optimization before repeating high-frequency operations.`
+      : `ssh operation completed in ${elapsedSeconds}s.`,
+    note: "Timing hint is written to stderr and intentionally does not echo the original remote command.",
+  };
+}
+
+export function formatSshRuntimeTimingHint(hint: SshRuntimeTimingHint): string {
+  return `UNIDESK_SSH_TIMING ${JSON.stringify(hint)}\n`;
+}
+
 function brokerSource(): string {
   return String.raw`
 const open = JSON.parse(process.argv[2] || process.argv[1] || "{}");
@@ -1690,6 +1751,7 @@ function terminalSize(): { cols: number; rows: number } {
 export async function runSsh(config: UniDeskConfig, providerId: string, args: string[]): Promise<number> {
   const invocation = parseSshInvocation(providerId, args);
   const parsed = invocation.parsed;
+  const startedAtMs = Date.now();
   const size = terminalSize();
   const openTimeoutMs = Math.max(15000, Number(process.env.UNIDESK_SSH_OPEN_TIMEOUT_MS || 60000));
   const payload = {
@@ -1751,25 +1813,33 @@ export async function runSsh(config: UniDeskConfig, providerId: string, args: st
   });
 
   return await new Promise<number>((resolve) => {
+    let settled = false;
     const restore = (): void => {
       process.stdin.unpipe(child.stdin);
       if (rawMode) process.stdin.setRawMode(false);
     };
-    child.on("error", (error) => {
+    const finish = (exitCode: number): void => {
+      if (settled) return;
+      settled = true;
       restore();
+      const hint = sshFailureHint(invocation.providerId, parsed, exitCode, stderrTail);
+      if (hint !== null) process.stderr.write(formatSshFailureHint(hint));
+      process.stderr.write(formatSshRuntimeTimingHint(sshRuntimeTimingHint({
+        invocation,
+        transport: "backend-core-broker",
+        exitCode,
+        startedAtMs,
+      })));
+      resolve(exitCode);
+    };
+    child.on("error", (error) => {
       const message = `unidesk ssh failed to start broker: ${error.message}\n`;
       appendStderrTail(message);
       process.stderr.write(message);
-      const hint = sshFailureHint(invocation.providerId, parsed, 255, stderrTail);
-      if (hint !== null) process.stderr.write(formatSshFailureHint(hint));
-      resolve(255);
+      finish(255);
     });
     child.on("close", (code) => {
-      restore();
-      const exitCode = code ?? 255;
-      const hint = sshFailureHint(invocation.providerId, parsed, exitCode, stderrTail);
-      if (hint !== null) process.stderr.write(formatSshFailureHint(hint));
-      resolve(exitCode);
+      finish(code ?? 255);
     });
   });
 }

scripts/ssh-argv-guidance-contract-test.ts

@@ -5,7 +5,7 @@ import path from "node:path";
 import { sshHelp } from "./src/help";
 import { providerTriageRecommendedCrossChecks } from "./src/provider-triage";
 import { remoteSshFrontendPlanForTest } from "./src/remote";
-import { formatSshFailureHint, parseSshArgs, parseSshInvocation, remoteApplyPatchSource, sshFailureHint } from "./src/ssh";
+import { formatSshFailureHint, formatSshRuntimeTimingHint, parseSshArgs, parseSshInvocation, remoteApplyPatchSource, sshFailureHint, sshRuntimeTimingHint } from "./src/ssh";
 
 type JsonRecord = Record<string, unknown>;
 
@@ -264,6 +264,30 @@ export function runSshArgvGuidanceContract(): JsonRecord {
   assertCondition(formatted.startsWith("UNIDESK_SSH_HINT "), "formatted hint must have structured prefix", formatted);
   assertCondition(!formatted.includes("echo hello"), "formatted hint must not echo the original remote command", formatted);
 
+  const timingInfo = sshRuntimeTimingHint({
+    invocation: parseSshInvocation("D601:/home/ubuntu/workspace/hwlab-dev", ["argv", "true"]),
+    transport: "backend-core-broker",
+    exitCode: 0,
+    startedAtMs: 1000,
+    finishedAtMs: 5200,
+    thresholdMs: 10_000,
+  });
+  assertCondition(timingInfo.level === "info" && timingInfo.slow === false, "short ssh operation should emit an info timing hint", timingInfo);
+  assertCondition(timingInfo.elapsedMs === 4200 && timingInfo.elapsedSeconds === 4.2, "timing hint must include elapsed ms and seconds", timingInfo);
+  const slowTiming = sshRuntimeTimingHint({
+    invocation: parseSshInvocation("D601", ["apply-patch"]),
+    transport: "frontend-websocket",
+    exitCode: 0,
+    startedAtMs: 0,
+    finishedAtMs: 12_345,
+    thresholdMs: 10_000,
+  });
+  assertCondition(slowTiming.level === "warning" && slowTiming.slow === true, "slow ssh operation should emit a warning timing hint", slowTiming);
+  assertCondition(slowTiming.message.includes("above the 10s warning threshold"), "slow timing warning must explain the threshold", slowTiming);
+  const formattedTiming = formatSshRuntimeTimingHint(slowTiming);
+  assertCondition(formattedTiming.startsWith("UNIDESK_SSH_TIMING "), "formatted timing hint must have structured prefix", formattedTiming);
+  assertCondition(!formattedTiming.includes("apply_patch"), "timing hint must not echo the original remote command", formattedTiming);
+
   const timeoutHint = sshFailureHint("D601", sshLike, 255, "unidesk ssh bridge timed out waiting for provider session");
   assertCondition(timeoutHint?.trigger === "timeout-or-kex", "provider session timeout must map to timeout-or-kex", timeoutHint);
 
@@ -281,6 +305,7 @@ export function runSshArgvGuidanceContract(): JsonRecord {
   assertCondition(helpText.includes("apply-patch [--allow-loose]") && helpText.includes("low-context update hunks"), "ssh help must document apply-patch loose-context guard", helpText);
   assertCondition(helpText.includes("ssh D601:k3s:hwlab-dev:hwlab-cloud-api script <<'SCRIPT'"), "ssh help must document k3s script operation", helpText);
   assertCondition(helpText.includes("UNIDESK_SSH_HINT"), "ssh help must document structured failure hint", helpText);
+  assertCondition(helpText.includes("UNIDESK_SSH_TIMING") && helpText.includes("10s"), "ssh help must document runtime timing hints", helpText);
 
   const crossChecks = providerTriageRecommendedCrossChecks("D601");
   assertCondition(crossChecks.includes("bun scripts/cli.ts ssh D601 argv true"), "provider triage cross-checks must keep argv true", crossChecks);
@@ -339,6 +364,7 @@ export function runSshArgvGuidanceContract(): JsonRecord {
       "post-provider k3s shorthand is rejected so location and operation stay separated",
       "k3s route stays location-only while operations fix native kubeconfig and assemble kubectl exec as argv",
       "ssh-like timeout/kex failures emit one structured argv retry hint",
+      "ssh runtime emits one structured timing hint on stderr and marks operations over 10 seconds as warnings",
       "help text documents stdin script passthrough and UNIDESK_SSH_HINT",
       "provider triage recommendedCrossChecks keeps ssh D601 argv true",
       "remote frontend ssh uses the same structured route parser for host, k3s and pod argv routes",