From 93c5a4c46f3113c521ef6fd5aa0a339d5442d9ca Mon Sep 17 00:00:00 2001 From: AskaEth Date: Wed, 7 Oct 2026 10:37:33 +0800 Subject: [PATCH] =?UTF-8?q?fix(browser):=20=E5=90=AF=E5=8A=A8=E5=A4=B1?= =?UTF-8?q?=E8=B4=A5=E8=A6=81=E8=AF=B4=E5=87=BA=E5=8E=9F=E5=9B=A0=EF=BC=9B?= =?UTF-8?q?=E9=A2=84=E7=AE=97=E8=80=97=E5=B0=BD=20=E2=89=A0=20=E6=B5=8F?= =?UTF-8?q?=E8=A7=88=E5=99=A8=E5=9D=8F=E4=BA=86?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 真机现象：主人看到 Chrome 窗口内有横幅（他读作「不支持接受的参数」），日志只有 一句「等待调试端口时被取消: context deadline exceeded」，看不出是谁的错。 三件（本片）： - 接住子进程 stdout/stderr（有界：前 4 KiB / 上报 12 行，只缓存不输出）⇒ 失败时 打一条带 exe / argv / chrome_output / chrome_output_bytes 的 WARN；成功只记字节数 （不刷屏）。 - 三种启动失败在错误里分开：① 进程立刻退出（profile 被占用）② 等端口超时 ③ 调用方预算耗尽（ctx 已结束 ⇒ **根本不 spawn**）。③ 与 ② 用两个截止时间比大小 区分 —— 顺带修掉一个老缺陷：原来 ctx 一结束就报「等待调试端口时被取消」，而那 几乎总是我们自己的 30s 用满，现被正确归到 ②。 - 降级档不再被**已耗尽**的轮预算连坐：如实报「预算耗尽 ⇒ 未尝试浏览器渲染， 这不是浏览器故障」，**不许把"没试"说成"试了失败"**。plugins/tools/io/bodyfetch.go 一字未动（fetchedBy / browserError 语义原样），只在**发起方**决定要不要发起。 对主人那条横幅的结论（有据，非推测）：那是 Chrome 的 **bad-flags 警告栏**，触发者 是 `--disable-blink-features=AutomationControlled` —— 它明确在 Chromium 的 kBadFlags 名单里（bad_flags_prompt.cc 列了 kDisableBlinkFeatures/kEnableBlinkFeatures），本机 Chrome 154 zh-CN 的文案是「您使用的是不受支持的命令行标记：$1。稳定性和安全性会 有所下降。」；而「不支持接受的参数」在 Chrome 的 zh-CN/en-US 资源与二进制里**零命中** ⇒ 是意译。⚠️ 该参数是 design/28 §2 要求的（掩盖 navigator.webdriver）⇒ 横幅是 **设计取舍的视觉副作用**，去掉它才消失（但会暴露自动化特征）。登记待主人裁决。 验收（主会话复跑 + 亲自变异）：go build ./... + 两包 vet 绿；browser 与 cmd/cyrene 两包测试绿；我用 -overlay 去掉 cmd.Stderr 接线 ⇒ TestDial_ReportsChromeOutputAndArgvOnLaunchFailure 变红（chrome_output="" chrome_output_bytes=0）。 ⚠️ 未部署：跑着的产物不含本片，要等下次 build + restart。 --- cmd/cyrene/wire_body_fallback.go | 42 +++- cmd/cyrene/wire_body_fallback_test.go | 102 +++++++++ .../capability/browser/fakebrowser_test.go | 143 +++++++++++++ internal/capability/browser/launch.go | 115 +++++++++- internal/capability/browser/launch_test.go | 198 ++++++++++++++++++ internal/capability/browser/launchoutput.go | 101 +++++++++ 6 files changed, 688 insertions(+), 13 deletions(-) create mode 100644 internal/capability/browser/fakebrowser_test.go create mode 100644 internal/capability/browser/launchoutput.go diff --git a/cmd/cyrene/wire_body_fallback.go b/cmd/cyrene/wire_body_fallback.go index 318def8..7a49134 100644 --- a/cmd/cyrene/wire_body_fallback.go +++ b/cmd/cyrene/wire_body_fallback.go @@ -28,6 +28,7 @@ import ( "context" "errors" "fmt" + "log/slog" "git.yeij.top/AskaEth/Cyrene_v2/internal/capability/browser" "git.yeij.top/AskaEth/Cyrene_v2/internal/capability/registry" @@ -66,9 +67,18 @@ func (a *app) bodyFallbackOption() iotools.Option { return iotools.WithBrowserFallback(nil) } log.Info("web-fetch browser fallback wired", "trigger", browserFallbackTrigger) - return iotools.WithBrowserFallback(&browserBodyRenderer{caps: a.caps}) + return iotools.WithBrowserFallback(&browserBodyRenderer{caps: a.caps, log: log}) } +// browserFallbackReasonBudget 是「这一档**没有发起**」的原因码：调用方这一轮的预算已经 +// 耗尽。它与 `no-usable-browser` 是两件事（一个是「没时间了」，一个是「没有浏览器」）， +// 混成一句会把人带偏（真机就出现过：窗口上是浏览器的抱怨，日志里像浏览器坏了）。 +const browserFallbackReasonBudget = "budget-exhausted" + +// browserFallbackBudgetNote 写清这一刻的**实际**含义：浏览器没坏、这一档没被尝试。 +// 它进错误文本（顺 web-fetch 的 browserError 面出来），因此必须一眼可读、不含猜测。 +const browserFallbackBudgetNote = "本轮工具预算已耗尽（调用方上下文已结束）⇒ 未尝试浏览器渲染，这不是浏览器故障" + // browserBodyRenderer 把浏览器能力面（`*browsercap.Manager.RenderText`）适配成 io 包的 // `iotools.BodyRenderer` —— 这是「进程内接口 + 依赖注入」的适配器，不引入第二个浏览器栈、 // 不新开任何监听端口（AGENTS §9）。 @@ -84,15 +94,43 @@ func (a *app) bodyFallbackOption() iotools.Option { // // 空正文**不在这里**判：`RenderText` 的「渲染成功但正文为空」是读数不是错误，而 io 的 // 降级档有自己的口径（`ErrEmptyRenderedBody`）—— 本适配器原样交出去，不替上层下结论。 -type browserBodyRenderer struct{ caps *registry.Registry } +type browserBodyRenderer struct { + caps *registry.Registry + // log 是挂载点的日志（已带来源）。可为 nil（单测直接构造）：那就不记，不做替代语义。 + log *slog.Logger +} // RenderBody 实现 iotools.BodyRenderer。 +// +// **预算口径**（design/28 §1 M5「降级档」+ §7 判据 4「如实标注」+ §6 坑 5「失败要如实报」， +// 设计没有为这一档规定独立预算 ⇒ 取最小的诚实口径）：ctx 已经结束（这一轮的工具预算耗尽 / +// 会话被取消）时**不发起**，如实报「预算耗尽 ⇒ 未尝试」，而**不是**报一个看起来像 +// 「浏览器坏了」的错误。三条理由： +// +// - 这一档要冷启动真浏览器（秒级），启动所需的预算此刻已经不存在； +// - 工具派发层在 ctx 结束时就要把结果丢掉（`internal/runtime/tool` 的 callTool 在 +// ctx.Done 与结果之间二选一，且 ctx 结束时返回 ctx.Err()）⇒ 硬起一个浏览器只会留下 +// 一个被立刻杀掉的窗口，**结果没人读**（真机踩过：窗口上跳出浏览器的抱怨）； +// - 没试过就不能报成「试了失败」：`fetchedBy` / `browserError` 的语义（见 +// `plugins/tools/io/bodyfetch.go`）一字不动，本适配器只交「没发起」这个事实。 +// +// ctx 还活着时**不动**它的预算（不另造一个第二预算）：浏览器会话可能是热的（同一次 +// 会话里刚渲染过），渲染只要一两秒；真有取消，浏览器侧会把它如实分类成「预算耗尽」 +// （见 `internal/capability/browser` 的分类标记），不会再冒充「浏览器坏了」。 func (r *browserBodyRenderer) RenderBody(ctx context.Context, rawURL string) (iotools.RenderedBody, error) { mgr := browserManagerOf(r.caps) if mgr == nil || !mgr.Available() { // 诚实降级：此时是「这一档没有来源」，**不是**「取到了空正文」。 return iotools.RenderedBody{}, errors.New("web-fetch browser fallback: no usable browser available") } + if err := ctx.Err(); err != nil { + if r.log != nil { + r.log.Info("web-fetch browser fallback not attempted", + "reason", browserFallbackReasonBudget, "error", err) + } + return iotools.RenderedBody{}, fmt.Errorf("web-fetch browser fallback: %s: %s: %w", + browserFallbackReasonBudget, browserFallbackBudgetNote, err) + } rendered, err := mgr.RenderText(ctx, rawURL) if err != nil { return iotools.RenderedBody{}, fmt.Errorf("browser render: %w", err) diff --git a/cmd/cyrene/wire_body_fallback_test.go b/cmd/cyrene/wire_body_fallback_test.go index 5fdd4a7..03bf49c 100644 --- a/cmd/cyrene/wire_body_fallback_test.go +++ b/cmd/cyrene/wire_body_fallback_test.go @@ -25,6 +25,7 @@ import ( "git.yeij.top/AskaEth/Cyrene_v2/internal/capability/browsercfg" "git.yeij.top/AskaEth/Cyrene_v2/internal/capability/registry" "git.yeij.top/AskaEth/Cyrene_v2/internal/config" + "git.yeij.top/AskaEth/Cyrene_v2/internal/logger" "git.yeij.top/AskaEth/Cyrene_v2/pkg/plugins/sdk" browsertools "git.yeij.top/AskaEth/Cyrene_v2/plugins/tools/browser" iotools "git.yeij.top/AskaEth/Cyrene_v2/plugins/tools/io" @@ -257,3 +258,104 @@ func TestWireRuntime_BrowserWiredBeforeIoTools(t *testing.T) { "会静默关死（挂载条件读的是注册面）") } } + +// ⑥ 预算口径：这一轮的预算已经耗尽（ctx 已结束）时，这一档**不发起**，如实报 +// 「预算耗尽 ⇒ 未尝试浏览器渲染」。判据是两句话都要在，而那句误导性的 +// 「启动本机浏览器失败」绝不能出现 —— 假 exe 一定启动失败，它出现就证明我们真去起了 +// 浏览器（那正是真机踩的坑：窗口上跳出浏览器的抱怨，日志里像浏览器坏了）。 +func TestBrowserBodyRenderer_ExhaustedBudgetIsNotABrowserFailure(t *testing.T) { + t.Parallel() + cfg := wsLoadConfig(t) + var out bytes.Buffer + a := browserTestApp(t, cfg, &out) + if err := a.caps.RegisterTool(browsertools.New( + newWiredBrowserManager(t, cfg, "example.com"))); err != nil { + t.Fatalf("注册 browser 工具: %v", err) + } + r := &browserBodyRenderer{caps: a.caps, log: logger.WithSource(a.log, ioLogSource)} + + cases := []struct { + name string + ctx func() (context.Context, context.CancelFunc) + }{ + {"已取消", func() (context.Context, context.CancelFunc) { + ctx, cancel := context.WithCancel(context.Background()) + cancel() + return ctx, cancel + }}, + {"已到期", func() (context.Context, context.CancelFunc) { + return context.WithTimeout(context.Background(), 0) + }}, + } + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + ctx, cancel := tc.ctx() + defer cancel() + got, err := r.RenderBody(ctx, "https://example.com/") + if err == nil { + t.Fatalf("预算耗尽时必须报错（不许拿空正文冒充成功）: %+v", got) + } + t.Logf("实测 err=%v", err) + msg := err.Error() + if !strings.Contains(msg, browserFallbackReasonBudget) { + t.Errorf("err = %v，应带原因码 %q", err, browserFallbackReasonBudget) + } + if !strings.Contains(msg, "未尝试浏览器渲染") { + t.Errorf("err = %v，应说清「没有试过」", err) + } + if strings.Contains(msg, "启动本机浏览器失败") { + t.Errorf("预算耗尽不许被报成浏览器故障: %v", err) + } + if strings.Contains(msg, "no usable browser") { + t.Errorf("「预算耗尽」与「没有可用来源」是两件事，不许混成一句: %v", err) + } + if got.Text != "" || got.Source != "" { + t.Errorf("失败时不该交出半个结论: %+v", got) + } + if !strings.Contains(out.String(), "reason="+browserFallbackReasonBudget) { + t.Errorf("日志里必须留下原因码（实得：%s）", out.String()) + } + if !strings.Contains(out.String(), "source="+ioLogSource) { + t.Errorf("这条日志必须带来源标签（AGENTS §10）：%s", out.String()) + } + }) + } +} + +// ⑦ 端到端（走生产接线的选项）：预算耗尽的那一轮，web-fetch 的错误里**两条档的真实遭遇 +// 都要在** —— 直连为什么没成 + 浏览器这一档为什么**没试**（预算耗尽）。io 层的 +// `fetchedBy` / `browserError` 语义不许变（那是它的红线），所以这里断言的是它们的**输出** +// 仍然照实：两条失败各自出现，谁也别替谁背锅。 +func TestBodyFallback_ExhaustedBudgetIsHonestEndToEnd(t *testing.T) { + t.Parallel() + cfg := wsLoadConfig(t) + var out bytes.Buffer + a := browserTestApp(t, cfg, &out) + srv := serveSkeletonPage(t) + if err := a.caps.RegisterTool(browsertools.New( + newWiredBrowserManager(t, cfg, endpointHost(srv)))); err != nil { + t.Fatalf("注册 browser 工具: %v", err) + } + tool := fallbackFetchTool(t, a, srv) + + ctx, cancel := context.WithCancel(context.Background()) + cancel() + got, err := tool.Execute(ctx, map[string]any{"url": srv.URL}) + if err == nil { + t.Fatalf("两条档都没成时必须报错（实得 %#v）", got) + } + t.Logf("实测 web-fetch 错误：%v", err) + msg := err.Error() + if !strings.Contains(msg, "browser fallback failed too") { + t.Errorf("io 层「两条失败都照实报」的口径不许变: %v", err) + } + if !strings.Contains(msg, browserFallbackReasonBudget) { + t.Errorf("浏览器那一档要如实说「预算耗尽 ⇒ 未尝试」: %v", err) + } + if strings.Contains(msg, "启动本机浏览器失败") { + t.Errorf("预算耗尽不许被说成浏览器故障（真去起了浏览器）: %v", err) + } + if got != nil { + t.Errorf("失败时不该交出结果: %#v", got) + } +} diff --git a/internal/capability/browser/fakebrowser_test.go b/internal/capability/browser/fakebrowser_test.go new file mode 100644 index 0000000..728791f --- /dev/null +++ b/internal/capability/browser/fakebrowser_test.go @@ -0,0 +1,143 @@ +package browser + +// 本文件是**假浏览器**：启动路径的测试必须真起一个子进程，才能证明 +// - 子进程的 stdout/stderr 被接住了（失败时上报、成功时不刷屏）； +// - 三种失败情形（进程立刻退出 / 端口没出来 / 预算没了）分辨得开。 +// +// 手法是 Go 里既有的「重跑自己」范式（stdlib `os/exec` 的 testhelper 同款，本仓 +// `internal/capability/plugin/manager_test.go` 的 MCP stdio 假 server 也用它）： +// 被当成浏览器拉起的可执行文件就是**测试二进制自己**（`os.Args[0]`），行为由 profile +// 目录里的一份脚本文件给出 —— 脚本落在 `Dial` 传 `--user-data-dir` 的那个目录里， +// 因此每个用例各说各话、可以并行。 +// +// `TestMain` 是接住它的唯一位置：子进程的 argv 是**浏览器参数**（没有 `-test.run`）， +// 到不了任何 Test 函数；不接住就会递归跑整个测试套件。 + +import ( + "bytes" + "encoding/json" + "fmt" + "log/slog" + "os" + "path/filepath" + "strconv" + "strings" + "testing" + "time" + + "git.yeij.top/AskaEth/Cyrene_v2/internal/logger" +) + +const ( + // fakeBrowserScriptFile 是假浏览器脚本的文件名（落在 profile 目录里）。 + fakeBrowserScriptFile = "fake-browser.json" + // fakeBrowserUserDataDirFlag 是脚本的定位方式：profile 目录就是 argv 里 + // `--user-data-dir=` 的值（真浏览器的同一个参数）。 + fakeBrowserUserDataDirFlag = "--user-data-dir=" + // fakeBrowserNoScriptExit 是「argv 像浏览器、但没有脚本」时的退出码：宁可表现得像 + // 一个立刻退出的浏览器，也不递归跑测试套件（那是测试基建事故，不是用例失败）。 + fakeBrowserNoScriptExit = 7 +) + +// fakeBrowserScript 是一次「假启动」的行为脚本（字段零值 = 不做那件事）。 +type fakeBrowserScript struct { + // Stdout / Stderr 是要写出去的若干行（模拟浏览器自己说的话）。 + Stdout []string `json:"stdout"` + Stderr []string `json:"stderr"` + // ExitCode 是退出码。 + ExitCode int `json:"exitCode"` + // WritePort > 0 ⇒ 往 profile 目录写 DevToolsActivePort（模拟真浏览器就绪）； + // Dial 只读这个文件，不会去连端口，所以端口号不必真的有人在听。 + WritePort int `json:"writePort"` + // SleepMS > 0 ⇒ 之后继续活着（模拟浏览器常驻）：由 Dial 的停止函数或超时路径 Kill。 + SleepMS int `json:"sleepMs"` +} + +// TestMain 让测试二进制可以**兼任**假浏览器。 +func TestMain(m *testing.M) { + if dir, ok := fakeBrowserProfileDir(os.Args[1:]); ok { + os.Exit(runFakeBrowser(dir)) + } + os.Exit(m.Run()) +} + +// fakeBrowserProfileDir 从 argv 里取出 profile 目录（找不到 ⇒ 这是普通的测试运行）。 +func fakeBrowserProfileDir(args []string) (string, bool) { + for _, a := range args { + if dir, ok := strings.CutPrefix(a, fakeBrowserUserDataDirFlag); ok { + return dir, true + } + } + return "", false +} + +// runFakeBrowser 按脚本演一次假浏览器，返回退出码。 +func runFakeBrowser(profileDir string) int { + raw, err := os.ReadFile(filepath.Join(profileDir, fakeBrowserScriptFile)) + if err != nil { + fmt.Fprintf(os.Stderr, "fake browser: %v\n", err) + return fakeBrowserNoScriptExit + } + var script fakeBrowserScript + if err := json.Unmarshal(raw, &script); err != nil { + fmt.Fprintf(os.Stderr, "fake browser: %v\n", err) + return fakeBrowserNoScriptExit + } + for _, line := range script.Stdout { + fmt.Fprintln(os.Stdout, line) + } + for _, line := range script.Stderr { + fmt.Fprintln(os.Stderr, line) + } + if script.WritePort > 0 { + content := strconv.Itoa(script.WritePort) + "\nfake-browser-guid\n" + if err := os.WriteFile(filepath.Join(profileDir, devToolsPortFile), []byte(content), 0o600); err != nil { + fmt.Fprintf(os.Stderr, "fake browser: %v\n", err) + return fakeBrowserNoScriptExit + } + } + if script.SleepMS > 0 { + time.Sleep(time.Duration(script.SleepMS) * time.Millisecond) + } + return script.ExitCode +} + +// newFakeChrome 造一个「可执行文件 = 测试二进制自己」的 localChrome，并把脚本写进 +// profile 目录（`Dial` 会把它当 `--user-data-dir` 传下来）。 +func newFakeChrome(t *testing.T, script fakeBrowserScript, timeout time.Duration, log *slog.Logger) *localChrome { + t.Helper() + exe, err := os.Executable() + if err != nil { + t.Fatalf("取测试二进制路径: %v", err) + } + dir := t.TempDir() + raw, err := json.Marshal(script) + if err != nil { + t.Fatalf("编码假浏览器脚本: %v", err) + } + if err := os.WriteFile(filepath.Join(dir, fakeBrowserScriptFile), raw, 0o600); err != nil { + t.Fatalf("写假浏览器脚本: %v", err) + } + return &localChrome{ + exe: exe, profileDir: dir, + viewportW: 1280, viewportH: 800, + timeout: timeout, log: log, + } +} + +// newCapturedLog 造一个把日志收进缓冲的 logger（带来源标签，与 discardLog 同源）。 +func newCapturedLog(level slog.Level) (*slog.Logger, *bytes.Buffer) { + var buf bytes.Buffer + base := slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: level})) + return logger.WithSource(base, logSource), &buf +} + +// escapedInLog 把字符串按 slog TextHandler 的转义规则处理：值里含空格/引号时它整段走 +// `strconv.Quote`（反斜杠变双反斜杠）；不含时原样输出。断言前把两种形态都认，免得 +// 「同一个路径在 exe= 里是单反斜杠、在 argv= 里是双反斜杠」这种细节把用例判红。 +func escapedInLog(s string) string { return strings.ReplaceAll(s, `\`, `\\`) } + +// containsInLog 报告日志里是否出现了这段文字（原样或 slog 的引号化形态）。 +func containsInLog(logs, want string) bool { + return strings.Contains(logs, want) || strings.Contains(logs, escapedInLog(want)) +} diff --git a/internal/capability/browser/launch.go b/internal/capability/browser/launch.go index 90ef0e5..ee5d211 100644 --- a/internal/capability/browser/launch.go +++ b/internal/capability/browser/launch.go @@ -2,6 +2,7 @@ package browser import ( "context" + "errors" "fmt" "log/slog" "os" @@ -35,6 +36,33 @@ const ( // 用的那一档）：它只问「端口有没有在听」，给得短。 const adoptProbeTimeout = 2 * time.Second +// 启动失败的**分类标记**：三种情形必须在错误消息里一眼可分（design/28 §7 判据 4 +// 「如实标注」/ §6 坑 5「失败要如实报」）—— +// +// ① 浏览器进程自己退了（参数被拒 / 委托给已跑实例 / profile 锁被占）； +// ② 我们自己的等待窗口用完（DevToolsActivePort 没出现）； +// ③ **调用方的预算先没了**：浏览器没坏，只是没时间了。 +// +// 哨兵仍然只有 ErrLaunch 一个（`errors.Is` 口径不变），这些标记是消息里可机读的那一段。 +const ( + // launchMarkerProcessExited 标记 ①。 + launchMarkerProcessExited = "浏览器进程立刻退出" + // launchMarkerPortTimeout 标记 ②。 + launchMarkerPortTimeout = "等 DevToolsActivePort 超时" + // launchMarkerBudget 标记 ③。 + launchMarkerBudget = "调用方预算耗尽" +) + +const ( + // chromeOutputDrainWait 是「进程退出/被杀之后，把它已经写进管道的输出收干净」的 + // 等待上限：诊断不该反过来拖住失败路径。 + chromeOutputDrainWait = 500 * time.Millisecond + // launchDeadlineSlack 容忍「调用方的截止时间与我们这一次等待的截止时间几乎同时」 + // 这种不可分情形：差值在它之内时按**我们自己等端口超时**报（此刻的事实正是这一次 + // 等待用满了配置的 timeout，真机常态如此：外层 openSession 与本次等待同源同值）。 + launchDeadlineSlack = 250 * time.Millisecond +) + // dialer 产出一个可用的 CDP HTTP 端点（`http://host:port`）与停止函数。它把 // 「启动本机浏览器」与「连接已跑端点」两条路统一成同一个会话装配入口。 type dialer interface { @@ -88,14 +116,22 @@ func (l *localChrome) Local() bool { return true } // Dial 拉起浏览器并等调试端口就绪。任何一步失败都返回带分类原因的 ErrLaunch。 // -// 两条**先于启动**的判定（都是为了让「上一次会话留下的浏览器」不至于把功能卡死）： +// 三条**先于启动**的判定（前两条是为了让「上一次会话留下的浏览器」不至于把功能卡死）： // -// 1. **认领已在跑的实例**：profile 目录的 DevToolsActivePort 还活着（端口在听）⇒ 直接 +// 1. **预算已耗尽就不起进程**：ctx 已经结束（这一轮的工具预算用完 / 会话被取消）时 +// 立刻返回「预算耗尽」分类，**不 spawn** —— 起了也只是生一个会被马上杀掉的窗口， +// 并把「没时间了」伪装成「浏览器起不来」（真机踩过：窗口上跳出浏览器的抱怨，日志 +// 里却像浏览器坏了）。判定做在**启动之前**，因为它要省掉的正是那次启动。 +// 2. **认领已在跑的实例**：profile 目录的 DevToolsActivePort 还活着（端口在听）⇒ 直接 // 出站连接它，**不再起第二个**。这不是优化，是**正确性**：同一个 user-data-dir 上起 // 第二个实例时 Chromium 会「委托给已在跑的那个」然后自己退出，于是新进程永远不写 // DevToolsActivePort ⇒ 功能会一直报启动超时，直到人工杀掉那个进程。认领把这一步 // 变成「复用」，也更贴合 design/28 §2「profile 长期保留、任务间复用」。 -// 2. **端口文件先清掉**：只在真的要走启动路径时才清，否则会把旧端口当成本次结果。 +// 3. **端口文件先清掉**：只在真的要走启动路径时才清，否则会把旧端口当成本次结果。 +// +// 子进程的 stdout/stderr **接进缓冲**（`chromeOutput`）：启动失败时把浏览器自己的话与 +// 本次 argv 一起报进日志 —— 这是「参数被拒 / 端口没出来 / 预算没了」三者可分的前提。 +// 成功时只报字节数（Debug），不把 Chrome 的常规输出刷进日志。 // // 停止函数只对**本次启动**的进程有效（认领来的实例不归我们杀）：进程退出后 Chrome 的 // 渲染进程随之退出，因此进程级 Kill 足够。 @@ -103,6 +139,9 @@ func (l *localChrome) Dial(ctx context.Context) (string, func(), error) { if strings.TrimSpace(l.exe) == "" { return "", nil, fmt.Errorf("%w: 未指定可执行文件", ErrLaunch) } + if err := ctx.Err(); err != nil { + return "", nil, budgetLaunchErr(ctx) + } if endpoint, ok := l.adoptExisting(ctx); ok { l.log.Info("browser session adopted", "endpoint", endpoint, "profile", l.profileDir) return endpoint, func() {}, nil @@ -112,24 +151,60 @@ func (l *localChrome) Dial(ctx context.Context) (string, func(), error) { } _ = os.Remove(filepath.Join(l.profileDir, devToolsPortFile)) - cmd := exec.Command(l.exe, l.launchArgs()...) + args := l.launchArgs() + cmd := exec.Command(l.exe, args...) + out := &chromeOutput{} + cmd.Stdout = out + cmd.Stderr = out if err := cmd.Start(); err != nil { return "", nil, fmt.Errorf("%w: 启动 %s: %v", ErrLaunch, l.exe, err) } exited := make(chan struct{}) go func() { defer close(exited) - _, _ = cmd.Process.Wait() + // 用 cmd.Wait（而不是 cmd.Process.Wait）：它会等两个输出复制协程收工， + // 于是 exited 关闭时缓冲里就是子进程说过的**全部**话（下面要在失败时上报它）。 + _ = cmd.Wait() }() port, err := l.waitDevToolsPort(ctx, exited) if err != nil { stopProcess(cmd) + l.waitExited(exited) + l.log.Warn("browser launch failed", + "exe", l.exe, + "argv", strings.Join(args, " "), + "chrome_output", out.preview(), + "chrome_output_bytes", out.totalBytes(), + "error", err) return "", nil, err } - l.log.Debug("browser launched", "exe", l.exe, "port", port, "profile", l.profileDir) + l.log.Debug("browser launched", + "exe", l.exe, "port", port, "profile", l.profileDir, "chrome_output_bytes", out.totalBytes()) return fmt.Sprintf("http://127.0.0.1:%d", port), func() { stopProcess(cmd) }, nil } +// waitExited 等子进程真正收尾（管道里的在途字节落进缓冲）再上报：Kill 之后 Wait 还要 +// 一点点时间，不等就会漏掉最后几行 —— 而最后几行往往正是原因。等不到就照现有内容报， +// 不把失败路径拖住。 +func (l *localChrome) waitExited(exited <-chan struct{}) { + timer := time.NewTimer(chromeOutputDrainWait) + defer timer.Stop() + select { + case <-exited: + case <-timer.C: + } +} + +// budgetLaunchErr 是 ③「调用方预算耗尽」的**唯一文案**。它必须读起来像「没时间了」， +// 而不是像「浏览器坏了」：取消与截止时间到分别点明（两者都是调用方自己的事）。 +func budgetLaunchErr(ctx context.Context) error { + detail := "上下文截止时间到（这一轮的工具预算已耗尽）" + if errors.Is(ctx.Err(), context.Canceled) { + detail = "上下文被取消（会话/这一轮已结束）" + } + return fmt.Errorf("%w: %s：%s，浏览器未启动完成", ErrLaunch, launchMarkerBudget, detail) +} + // adoptExisting 报告 profile 目录里记录的调试端点是否**仍然活着**；活着就返回它。 // 探测超时给得很短：这是一个「要不要复用」的判断，不该拖住启动路径。 func (l *localChrome) adoptExisting(ctx context.Context) (string, bool) { @@ -175,10 +250,20 @@ func (l *localChrome) launchArgs() []string { return args } -// waitDevToolsPort 等 DevToolsActivePort 出现并解析出端口号。三条出口都要**说清原因**： -// 进程立刻退出（多半是 profile 锁被占 / 浏览器已在运行）、ctx 取消、超时。 +// waitDevToolsPort 等 DevToolsActivePort 出现并解析出端口号。三条出口都要**说清原因**， +// 而且三者互不冒充（design/28 §7 判据 4「如实标注」）： +// +// ① 浏览器进程自己退了（多半是 profile 锁被占 / 浏览器已在运行）——错误里带 +// launchMarkerProcessExited； +// ② 我们自己的等待窗口用完 —— 带 launchMarkerPortTimeout； +// ③ 调用方的预算先没了（ctx 结束）—— 带 launchMarkerBudget，**不**说浏览器坏。 +// +// ② 与 ③ 的分辨靠两者的截止时间：ctx 的截止时间**明显早于**我们这一次等待的截止时间 +// 时，结束它的是调用方；几乎同时到点时按 ② 报（那是这一次等待真的用满了配置的 timeout， +// 也是真机常态：外层 openSession 的预算与本次等待同源同值）。 func (l *localChrome) waitDevToolsPort(ctx context.Context, exited <-chan struct{}) (int, error) { path := filepath.Join(l.profileDir, devToolsPortFile) + launchDeadline := time.Now().Add(l.timeout) deadline := time.NewTimer(l.timeout) defer deadline.Stop() ticker := time.NewTicker(portPollInterval) @@ -192,16 +277,24 @@ func (l *localChrome) waitDevToolsPort(ctx context.Context, exited <-chan struct // 浏览器进程自己退了，端口不会再出现 —— **立刻**报，不把超时白等完。 // 最常见的原因是同一 profile 已被另一个实例占用（Chromium 的 profile 锁） // 或浏览器已被别处启动：委托出去的新进程不写 DevToolsActivePort。 - return 0, fmt.Errorf("%w: 浏览器进程立刻退出（多半是该 profile 已被另一个实例占用）", ErrLaunch) + return 0, fmt.Errorf("%w: %s（多半是该 profile 已被另一个实例占用）", ErrLaunch, launchMarkerProcessExited) case <-ctx.Done(): - return 0, fmt.Errorf("%w: 等待调试端口时被取消: %v", ErrLaunch, ctx.Err()) + if dl, ok := ctx.Deadline(); !ok || dl.Add(launchDeadlineSlack).Before(launchDeadline) { + return 0, budgetLaunchErr(ctx) + } + return 0, l.portTimeoutErr() case <-deadline.C: - return 0, fmt.Errorf("%w: 等 %s 超时（%s）", ErrLaunch, devToolsPortFile, l.timeout) + return 0, l.portTimeoutErr() case <-ticker.C: } } } +// portTimeoutErr 是 ②「我们自己的等待窗口用完」的唯一文案（两条出口共用，口径只有一处）。 +func (l *localChrome) portTimeoutErr() error { + return fmt.Errorf("%w: %s（%s）", ErrLaunch, launchMarkerPortTimeout, l.timeout) +} + // readDevToolsPort 读端口文件的首行；文件还没出现 / 还没写完 / 内容不合法都返回 false // （交给调用方继续轮询，而不是把「正在写」误判成「配错」）。 func readDevToolsPort(path string) (int, bool) { diff --git a/internal/capability/browser/launch_test.go b/internal/capability/browser/launch_test.go index 6b0ee9f..f7d50cf 100644 --- a/internal/capability/browser/launch_test.go +++ b/internal/capability/browser/launch_test.go @@ -2,6 +2,8 @@ package browser import ( "context" + "errors" + "log/slog" "net/http" "net/http/httptest" "os" @@ -193,3 +195,199 @@ func containsArg(args []string, want string) bool { } return false } + +// ── 启动失败的可诊断性与分类（假浏览器见 fakebrowser_test.go） ────────────────────── + +// TestDial_ReportsChromeOutputAndArgvOnLaunchFailure 是本片最重要的一条：启动失败时 +// **必须**把浏览器自己说的话与本次 argv 一起报进日志。真机踩过的坑正是这条的反面 —— +// 窗口上跳出浏览器的抱怨，我们的日志里却只有自己这一侧的猜测（"等待调试端口时被取消"）， +// 于是「浏览器为什么拒绝」永远查不到。 +func TestDial_ReportsChromeOutputAndArgvOnLaunchFailure(t *testing.T) { + t.Parallel() + const complaint = "不支持的标记: --remote-allow-origins=*" + log, buf := newCapturedLog(slog.LevelDebug) + l := newFakeChrome(t, fakeBrowserScript{Stderr: []string{complaint}, ExitCode: 2}, 5*time.Second, log) + + _, stop, err := l.Dial(context.Background()) + if stop != nil { + t.Error("失败路径不该交出停止函数") + } + if err == nil { + t.Fatal("假浏览器立刻退出时 Dial 必须报错") + } + if !errors.Is(err, ErrLaunch) { + t.Fatalf("错误必须仍然包住 ErrLaunch（errors.Is 口径不变）: %v", err) + } + if !strings.Contains(err.Error(), launchMarkerProcessExited) { + t.Errorf("错误里应点明「进程立刻退出」这一类: %v", err) + } + + logs := buf.String() + t.Logf("实测 error=%v\n实测日志=%s", err, logs) + for _, want := range []string{ + complaint, // 浏览器自己说的话 + l.exe, // 是哪个可执行文件 + "--user-data-dir=" + l.profileDir, // 本次 argv（profile 路径不含凭据） + "--remote-debugging-port=0", + "chrome_output_bytes=", + } { + if !containsInLog(logs, want) { + t.Errorf("失败日志里缺少 %q：\n%s", want, logs) + } + } +} + +// TestDial_SuccessDoesNotSpamChromeOutput 钉住反面：**成功时不刷屏**。正常启动时 +// Chrome 也会往 stderr 写常规信息，那些不该进日志；只留一个字节数（Debug，供排查用）。 +func TestDial_SuccessDoesNotSpamChromeOutput(t *testing.T) { + t.Parallel() + const chatter = "DevTools listening on ws://127.0.0.1:55543" + log, buf := newCapturedLog(slog.LevelDebug) + l := newFakeChrome(t, fakeBrowserScript{ + Stderr: []string{chatter}, WritePort: 55543, SleepMS: 5000, + }, 5*time.Second, log) + + endpoint, stop, err := l.Dial(context.Background()) + if err != nil { + t.Fatalf("脚本写了端口文件，Dial 应当成功: %v", err) + } + defer stop() + if endpoint != "http://127.0.0.1:55543" { + t.Errorf("endpoint = %q", endpoint) + } + logs := buf.String() + if containsInLog(logs, chatter) { + t.Errorf("成功启动时不该把浏览器自己的输出打进日志（刷屏）：\n%s", logs) + } + if !strings.Contains(logs, "browser launched") || !strings.Contains(logs, "chrome_output_bytes=") { + t.Errorf("成功时只应留一条只报规模（字节数）的 Debug：\n%s", logs) + } +} + +// TestDial_ExhaustedBudgetDoesNotSpawnBrowser 钉住预算口径的**起点**：ctx 已经结束时 +// **不起进程** —— 起了也只是生一个会被马上杀掉的窗口，并把「没时间了」伪装成 +// 「浏览器起不来」。 +func TestDial_ExhaustedBudgetDoesNotSpawnBrowser(t *testing.T) { + t.Parallel() + log, buf := newCapturedLog(slog.LevelDebug) + l := newFakeChrome(t, fakeBrowserScript{ + Stderr: []string{"这一行不该出现：进程根本没被拉起"}, WritePort: 55543, SleepMS: 5000, + }, 5*time.Second, log) + + ctx, cancel := context.WithCancel(context.Background()) + cancel() + _, _, err := l.Dial(ctx) + if err == nil { + t.Fatal("预算已耗尽时 Dial 必须报错") + } + t.Logf("实测错误（ctx 已取消）：%v", err) + if !errors.Is(err, ErrLaunch) { + t.Fatalf("错误必须仍然包住 ErrLaunch: %v", err) + } + if !strings.Contains(err.Error(), launchMarkerBudget) { + t.Errorf("错误必须读成「预算耗尽」，实得: %v", err) + } + if strings.Contains(err.Error(), launchMarkerPortTimeout) { + t.Errorf("预算耗尽不许被说成「端口等超时」（那是浏览器侧的问题）: %v", err) + } + if _, ok := readDevToolsPort(filepath.Join(l.profileDir, devToolsPortFile)); ok { + t.Error("预算耗尽时不该起浏览器（脚本被执行了）") + } + if strings.Contains(buf.String(), "这一行不该出现") { + t.Errorf("预算耗尽时子进程不该存在:\n%s", buf.String()) + } +} + +// TestDial_CallerDeadlineIsReportedAsBudget 钉住**真机那条路**：等待期间调用方的截止 +// 时间到了（这一轮的工具预算烧完），错误必须读成「预算耗尽、浏览器没坏」，而不是 +// 「等待调试端口时被取消」这种既像浏览器故障、又说不清谁取消的文案。 +func TestDial_CallerDeadlineIsReportedAsBudget(t *testing.T) { + t.Parallel() + log, buf := newCapturedLog(slog.LevelDebug) + l := newFakeChrome(t, fakeBrowserScript{Stderr: []string{"浏览器在等，但没人给它时间"}, SleepMS: 5000}, 10*time.Second, log) + + ctx, cancel := context.WithTimeout(context.Background(), 200*time.Millisecond) + defer cancel() + _, _, err := l.Dial(ctx) + if err == nil { + t.Fatal("调用方截止时间到之后 Dial 必须报错") + } + if !errors.Is(err, ErrLaunch) { + t.Fatalf("错误必须仍然包住 ErrLaunch: %v", err) + } + if !strings.Contains(err.Error(), launchMarkerBudget) { + t.Errorf("错误必须读成「预算耗尽」，实得: %v", err) + } + if strings.Contains(err.Error(), launchMarkerPortTimeout) { + t.Errorf("调用方预算先到时不许报成我们自己的端口等待超时: %v", err) + } + if !containsInLog(buf.String(), l.profileDir) { + t.Errorf("这条失败也要带 argv（否则现场没法复现）:\n%s", buf.String()) + } +} + +// TestDial_ThreeLaunchFailuresAreDistinguishable 钉住「一眼分辨」：三条出口 —— +// ① 进程立刻退出 / ② 我们自己的端口等待超时 / ③ 调用方预算耗尽 —— 各自的错误文案里 +// 必须带**互不相同**的标记，谁也别冒充谁。 +func TestDial_ThreeLaunchFailuresAreDistinguishable(t *testing.T) { + t.Parallel() + cases := []struct { + name string + script fakeBrowserScript + timeout time.Duration + ctx func() (context.Context, context.CancelFunc) + wantMarker string + forbid string + }{ + { + name: "①进程立刻退出", + script: fakeBrowserScript{Stderr: []string{"参数被拒，进程退出"}, ExitCode: 1}, + timeout: 5 * time.Second, + ctx: func() (context.Context, context.CancelFunc) { return context.WithCancel(context.Background()) }, + wantMarker: launchMarkerProcessExited, + forbid: launchMarkerBudget, + }, + { + name: "②等端口超时", + script: fakeBrowserScript{Stderr: []string{"起来了但从不写端口文件"}, SleepMS: 5000}, + timeout: 300 * time.Millisecond, + ctx: func() (context.Context, context.CancelFunc) { return context.WithCancel(context.Background()) }, + wantMarker: launchMarkerPortTimeout, + forbid: launchMarkerBudget, + }, + { + name: "③调用方预算耗尽", + script: fakeBrowserScript{Stderr: []string{"还没就绪预算就没了"}, SleepMS: 5000}, + timeout: 10 * time.Second, + ctx: func() (context.Context, context.CancelFunc) { + return context.WithTimeout(context.Background(), 200*time.Millisecond) + }, + wantMarker: launchMarkerBudget, + forbid: launchMarkerPortTimeout, + }, + } + seen := map[string]string{} + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + l := newFakeChrome(t, tc.script, tc.timeout, discardLog()) + ctx, cancel := tc.ctx() + defer cancel() + _, _, err := l.Dial(ctx) + if err == nil { + t.Fatal("这一档必须报错") + } + msg := err.Error() + t.Logf("%s 实测错误：%v", tc.name, err) + if !strings.Contains(msg, tc.wantMarker) { + t.Errorf("错误里应带标记 %q：%v", tc.wantMarker, err) + } + if strings.Contains(msg, tc.forbid) { + t.Errorf("错误里不该出现 %q（冒充了另一类失败）：%v", tc.forbid, err) + } + if prev, dup := seen[tc.wantMarker]; dup { + t.Errorf("标记 %q 与 %q 撞了 —— 三种情形必须可分", tc.wantMarker, prev) + } + seen[tc.wantMarker] = tc.name + }) + } +} diff --git a/internal/capability/browser/launchoutput.go b/internal/capability/browser/launchoutput.go new file mode 100644 index 0000000..4d1bfd9 --- /dev/null +++ b/internal/capability/browser/launchoutput.go @@ -0,0 +1,101 @@ +package browser + +import ( + "strconv" + "strings" + "sync" + "unicode/utf8" +) + +// 接住子进程输出的两个上限（AGENTS §10：不出现裸魔法数字）。 +const ( + // chromeOutputMaxBytes 是缓存的**前缀**字节数。为什么留前 N 而不是后 N：Chrome 的 + // 抱怨/崩溃信息总在开头，而尾部的常规日志量最大 —— 留头既省内存又留下原因。 + chromeOutputMaxBytes = 4096 + // chromeOutputMaxLines 是失败上报时最多打出的行数（前 N 行）。 + chromeOutputMaxLines = 12 +) + +// 本文件只做一件事：**接住浏览器自己说的话**。design/28 §6 坑 5「失败要如实报」 +// 的落地前提是「看得见失败」—— 启动失败时浏览器把原因写在自己的 stdout/stderr 上 +// （参数被拒、profile 锁、崩溃），不接住它，日志里就只剩我们这一侧的猜测。 +// +// 两条口径： +// +// - **有界**：只留前 N 字节 / 上报前 N 行。正常启动时 Chrome 也会往 stderr 写常规 +// 信息，全打进日志就是刷屏；缓存也无上限地吃内存。 +// - **不主动打**：本类型只缓存，**不输出**。成功时只报字节数（Debug），失败时由 +// `localChrome.Dial` 一次性把前 N 行与本次 argv 一起报出来（见 launch.go）。 +type chromeOutput struct { + mu sync.Mutex + head []byte + total int + truncated bool +} + +// Write 实现 io.Writer。stdout 与 stderr 是两条独立的管道，`os/exec` 为它们各起一个 +// 复制协程 ⇒ 必须加锁。它**永不返回错误**：缓存失败不能反过来弄坏子进程的写入。 +func (o *chromeOutput) Write(p []byte) (int, error) { + o.mu.Lock() + defer o.mu.Unlock() + o.total += len(p) + room := chromeOutputMaxBytes - len(o.head) + if room <= 0 { + if len(p) > 0 { + o.truncated = true + } + return len(p), nil + } + if len(p) > room { + o.head = append(o.head, p[:room]...) + o.truncated = true + return len(p), nil + } + o.head = append(o.head, p...) + return len(p), nil +} + +// totalBytes 报告子进程一共写了多少字节（截断时也照实报，不拿留下的那部分当全部）。 +func (o *chromeOutput) totalBytes() int { + o.mu.Lock() + defer o.mu.Unlock() + return o.total +} + +// preview 返回失败上报用的「前 N 行」：每行内的空白压成单空格、空行去掉；被截断时 +// 在末尾点明**截断与总字节数**（绝不把半截输出说得像完整输出）。没有输出时返回空串， +// 调用方据此判断「浏览器一个字都没说」。 +func (o *chromeOutput) preview() string { + o.mu.Lock() + raw := truncateRune(o.head) + truncated := o.truncated + total := o.total + o.mu.Unlock() + + kept := make([]string, 0, chromeOutputMaxLines) + for _, line := range strings.Split(raw, "\n") { + line = strings.Join(strings.Fields(line), " ") + if line == "" { + continue + } + kept = append(kept, line) + if len(kept) == chromeOutputMaxLines { + truncated = true + break + } + } + text := strings.Join(kept, " | ") + if truncated && text != "" { + text += " | ...(已截断，共 " + strconv.Itoa(total) + " 字节)" + } + return text +} + +// truncateRune 去掉尾部可能被切断的半个 UTF-8 字符（按字节截断的代价）：最多回退 +// utf8.UTFMax-1 个字节，不因个别非法字节丢掉整段可读输出。 +func truncateRune(raw []byte) string { + for i := 0; i < utf8.UTFMax-1 && len(raw) > 0 && !utf8.Valid(raw); i++ { + raw = raw[:len(raw)-1] + } + return string(raw) +}