From c787ebebd6666852f229bed3bc4ea9047b509168 Mon Sep 17 00:00:00 2001 From: Ji Mao Cai <44921326+jinghero@users.noreply.github.com> Date: Tue, 10 Nov 2026 16:35:38 +0800 Subject: [PATCH] =?UTF-8?q?fix:=20=E4=BF=9D=E7=95=99=20uv=20=E6=89=A7?= =?UTF-8?q?=E8=A1=8C=E8=AF=8A=E6=96=AD=E5=B9=B6=E8=A1=A5=E9=BD=90=E5=A4=B1?= =?UTF-8?q?=E8=B4=A5=E6=97=A5=E5=BF=97=20(T5.17)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- ...61\350\264\245\350\257\212\346\226\255.md" | 10 +++ ...61\350\264\245\350\257\212\346\226\255.md" | 40 +++++++++++ ...73\345\212\241\346\213\206\345\210\206.md" | 9 +++ internal/cli/bootstrap_update_test.go | 66 ++++++++++++------- internal/cli/cli.go | 5 +- internal/cli/session.go | 27 +++++++- internal/uv/bootstrap.go | 7 +- internal/uv/bootstrap_test.go | 34 ++++++++++ 8 files changed, 168 insertions(+), 30 deletions(-) create mode 100644 "doc/current/M5/\350\256\241\345\210\222-T5.17-uv\346\211\247\350\241\214\345\244\261\350\264\245\350\257\212\346\226\255.md" create mode 100644 "doc/current/M5/\350\256\276\350\256\241-T5.17-uv\346\211\247\350\241\214\345\244\261\350\264\245\350\257\212\346\226\255.md" diff --git "a/doc/current/M5/\350\256\241\345\210\222-T5.17-uv\346\211\247\350\241\214\345\244\261\350\264\245\350\257\212\346\226\255.md" "b/doc/current/M5/\350\256\241\345\210\222-T5.17-uv\346\211\247\350\241\214\345\244\261\350\264\245\350\257\212\346\226\255.md" new file mode 100644 index 0000000..c0f6344 --- /dev/null +++ "b/doc/current/M5/\350\256\241\345\210\222-T5.17-uv\346\211\247\350\241\214\345\244\261\350\264\245\350\257\212\346\226\255.md" @@ -0,0 +1,10 @@ +# T5.17 实施计划 + +1. 扩展 `internal/uv/bootstrap_test.go` 与 `internal/cli/bootstrap_update_test.go`。 + 红灯命令：`go test ./internal/uv ./internal/cli -run 'TestBootstrap_(CachedExecutableFailurePreservesDiagnostics|FailureIsRecordedInOperationLog)$' -count=1 -v`。 + 前者应缺失 Windows 错误号，后者应缺失真实日志文件中的失败记录。 +2. 修改 `wrapBootstrapError` 与会话终态日志处理，使用同一命令复跑至绿灯。 +3. 运行 gofmt、`go vet ./...`、`go build ./...`、`go test -p 1 ./... -count=1`、 + `git diff --check`，复核 stdout 所有权、错误优先级、Sentry 净化及未打开日志的早期失败。 +4. 记录实际结果，归档设计，删除本计划。用户已授权提交、推送开发分支并创建正式 PR， + 不直推主分支或发版。 diff --git "a/doc/current/M5/\350\256\276\350\256\241-T5.17-uv\346\211\247\350\241\214\345\244\261\350\264\245\350\257\212\346\226\255.md" "b/doc/current/M5/\350\256\276\350\256\241-T5.17-uv\346\211\247\350\241\214\345\244\261\350\264\245\350\257\212\346\226\255.md" new file mode 100644 index 0000000..a7cf2ec --- /dev/null +++ "b/doc/current/M5/\350\256\276\350\256\241-T5.17-uv\346\211\247\350\241\214\345\244\261\350\264\245\350\257\212\346\226\255.md" @@ -0,0 +1,40 @@ +# T5.17 uv 执行失败诊断 + +CNB #263 的 bootstrap 日志只有清理和磁盘信息，无法说明 uv 为何不能执行。 +`wrapBootstrapError` 保留错误码但丢弃底层 details；命令的日志器在返回前关闭， +会话随后写失败记录时得到 `logging.ErrClosed`，现有内存日志替身未模拟关闭。 + +## 处理方式 + +- uv 包装复制已类型化错误的 details，保留原错误链、错误码和现有阶段。 + 不添加原始 error 文本、命令行或环境变量。 +- 会话在命令收尾后、发射失败终态前，为已经打开过操作日志的命令创建独立日志器。 + 沿用命令名、operationId 和受管日志工厂，记录最终分类后的失败，再关闭日志器。 + 剥离取消信号并使用现有有界清理预算；日志打开、写入或关闭失败只写本地 stderr， + 不改变主错误、退出码、状态或 remediation。 +- 未打开过操作日志的早期失败仍不创建日志目录，保留原有状态写入错误的 stderr 诊断。 +- Electron 不改动。Sentry 继续经现有白名单净化，不增加事件或自由文本字段。 + +将全部业务日志器的生命周期移交会话会改变 workspace、锁和状态收尾的错误优先级， +因此采用独立终态日志器。它只在真实失败且已有操作日志时打开，不增加成功路径 I/O。 + +## 验证 + +扩展 bootstrap 的既有失败落盘测试，使用真实日志器并回读 JSON 行，核对错误码、阶段、 +失败类别、Windows 错误号与 operationId，且只有一条 error 记录。 +uv 包通过缓存自检入口注入可达的执行失败，确认包装保留 details 和错误链。 +先确认两项回归在原实现失败，再运行 uv、CLI、日志及全仓标准门。 + +## 本地证据 + +- 两项回归在未修复代码上分别因 details 为空、真实日志没有 error 记录而失败； + 修复后相同命令通过，连同离线、下载失败、取消、停采和日志关闭约束重复 10 轮通过。 +- 新编译 EXE 在隔离目录中执行损坏的受管 uv 文件，离线且关闭遥测。 + 先直接启动同一文件取得 Windows 原始错误号，再核对 Runtime 的结果和日志。 + 实测退出码 50、`UV_EXEC_FAILED`、`start_failed`、Windows 错误号 216； + `debug/runtime/bootstrap-20261110.log` 中同一 operationId 恰好一条失败记录。 +- `go vet ./...`、`go build ./...`、固定版本 `govulncheck@v1.9.0` 均退出 0。 +- 未修改基线 `116a045` 使用 `go test -p 1 ./... -count=1` 退出 1， + 出现 runtime-state 临时目录清理失败和 SUBST 夹具的 W: 盘未就绪。 + 修复版相同命令也退出 1，失败仍为这两类；CLI、uv、日志、协议及遥测包通过。 + 这些本机限制不作为本次改动通过全量测试的证据，完整门禁仍需远端 CI 确认。 diff --git "a/doc/\344\273\273\345\212\241\346\213\206\345\210\206.md" "b/doc/\344\273\273\345\212\241\346\213\206\345\210\206.md" index 46d7156..e32bcdc 100644 --- "a/doc/\344\273\273\345\212\241\346\213\206\345\210\206.md" +++ "b/doc/\344\273\273\345\212\241\346\213\206\345\210\206.md" @@ -627,6 +627,12 @@ D6 的推论（重要）：`workspace sync` 按内部模板 `release/<完整版 ### - [x] M5 uv、Python 与依赖（internal/uv） ✅ 2026-10-22 `6fb4b81` +- [ ] **T5.17 uv 执行失败诊断与失败日志落盘**（S） 🚧 + - 依赖：T5.1、T5.2、T5.16；来源：[AUTO-MAS CNB #263](https://cnb.cool/AUTO-MAS-Project/AUTO-MAS/-/issues/263)。 + - 内容：uv 准备包装保留底层结构化细节；命令资源收尾后以同一命令和操作编号打开终态日志器，记录最终失败，避免写入已关闭的日志器。 + - 验收：缓存 uv 自检启动失败保留失败类别和 Windows 错误号；真实本地日志含唯一失败记录；错误码、取消、状态和清理语义不变；标准门通过。 + - 设计与计划：[设计](./current/M5/设计-T5.17-uv执行失败诊断.md)、[计划](./current/M5/计划-T5.17-uv执行失败诊断.md)。 + - [x] **T5.16 uv 下载失败诊断** ✅ 2026-10-23 `8784e75` - 依赖：T5.1、T12.9；内容：共用结构化网络分类、逐源详情与 HTTP 状态；验收：分类/换源/取消/发布事实及脱敏矩阵、标准门。 - 证据：分类、逐源 HTTP 状态与精确耗时、脱敏及下载回归通过；[四项共同验收](./archive/M12/设计-运行时失败诊断补齐.md)。 @@ -1666,6 +1672,9 @@ T6.1～T6.7 固定测试名、Windows/race 门和双审清零规则完成；已 ## 7. 变更记录 +2026-11-10：按 AUTO-MAS CNB #263 登记 T5.17，保留 uv 准备失败的结构化详情， +补齐命令日志器关闭后的最终失败落盘；范围限定 Runtime，不修改 Electron。 + 2026-11-10：登记 T12.10，按 Sentry 事件与离线探针修正普通失败分组和应用栈，补齐已知后端身份、 初始/清理分类与终止请求事实；保持错误四元组和生命周期，不上传原始文本，不访问生产 Sentry 验收。 diff --git a/internal/cli/bootstrap_update_test.go b/internal/cli/bootstrap_update_test.go index acf6d01..adc7406 100644 --- a/internal/cli/bootstrap_update_test.go +++ b/internal/cli/bootstrap_update_test.go @@ -3,6 +3,7 @@ package cli import ( "bytes" "context" + "encoding/json" "errors" "io" "os" @@ -14,7 +15,6 @@ import ( "github.com/AUTO-MAS-Project/AUTO-MAS-Runtime/internal/config" "github.com/AUTO-MAS-Project/AUTO-MAS-Runtime/internal/filesystem" "github.com/AUTO-MAS-Project/AUTO-MAS-Runtime/internal/gitrepo" - "github.com/AUTO-MAS-Project/AUTO-MAS-Runtime/internal/logging" "github.com/AUTO-MAS-Project/AUTO-MAS-Runtime/internal/mirror" "github.com/AUTO-MAS-Project/AUTO-MAS-Runtime/internal/protocol" "github.com/AUTO-MAS-Project/AUTO-MAS-Runtime/internal/state" @@ -320,47 +320,63 @@ func writeBootstrapFile(t *testing.T, path string) { } } -// TestBootstrap_FailureIsRecordedInOperationLog 钉住「失败必须落盘」：此前 Runtime 的 -// 操作日志只透传 uv 输出与清理统计，失败本身、错误码与 stage 一条都不写——真机上取到 -// 2468 行日志全是 info，零 warn 零 error，用户报上来也无从查起。 +// TestBootstrap_FailureIsRecordedInOperationLog 使用真实日志器验证收尾后失败仍能落盘。 func TestBootstrap_FailureIsRecordedInOperationLog(t *testing.T) { root := t.TempDir() - log := &m5TestLog{} - environment := &m5TestEnvironment{calls: &log.calls} - store := &m5TestStateStore{calls: &log.calls} - workspace := workspaceTestService{sync: func(context.Context, gitrepo.SyncRequest) (gitrepo.SyncResult, error) { - return gitrepo.SyncResult{}, errors.New("clone failed") + var calls []string + environment := &m5TestEnvironment{calls: &calls, uvErr: &commandError{ + code: protocol.CodeUVExecFailed, stage: protocol.StageUVVerify, message: "uv 准备失败", + details: map[string]any{"failureKind": "start_failed", "windowsError": uint64(5)}, }} + store := &m5TestStateStore{calls: &calls} var stdout, stderr bytes.Buffer code := Execute(t.Context(), []string{"--app-root", root, "--output", "ndjson", "bootstrap", "--version", "v5.4.0"}, IO{In: strings.NewReader(""), Out: &stdout, Err: &stderr}, WithCWD(root), WithEnvironmentFactory(func(*config.Layout) (environmentService, error) { return environment, nil }), - WithWorkspaceFactory(func(*config.Layout) (workspaceService, error) { return workspace, nil }), WithEnvironmentStateStoreFactory(func(context.Context, *config.Layout, func() time.Time) (environmentStateStore, error) { return store, nil }), WithMutationCoordinatorFactory(func(context.Context, *config.Layout) (gitrepo.MutationCoordinator, error) { - return &m5TestCoordinator{calls: &log.calls}, nil - }), - WithWorkspaceLoggerFactory(func(context.Context, *config.Layout, io.Writer, string, string, func() time.Time) (workspaceLogger, error) { - return log, nil + return &m5TestCoordinator{calls: &calls}, nil }), ) - if code == 0 { - t.Fatalf("bootstrap exit=0, want failure; output=%s", stdout.String()) + if code != protocol.ExitCodeEnvironmentFailure { + t.Fatalf("bootstrap exit=%d, want UV_EXEC_FAILED exit; output=%s", code, stdout.String()) } - var failure *m5LogRecord - for i := range log.records { - if log.records[i].level == logging.LevelError { - failure = &log.records[i] - break + layout, err := config.NewLayout(root, root) + if err != nil { + t.Fatal(err) + } + paths, err := filepath.Glob(filepath.Join(layout.RuntimeLogDir(), "bootstrap-*.log")) + if err != nil || len(paths) != 1 { + t.Fatalf("bootstrap log paths = %v, error = %v", paths, err) + } + data, err := os.ReadFile(paths[0]) + if err != nil { + t.Fatal(err) + } + var failures []map[string]any + for _, line := range bytes.Split(bytes.TrimSpace(data), []byte{'\n'}) { + var entry map[string]any + if err := json.Unmarshal(line, &entry); err != nil { + t.Fatal(err) + } + if entry["level"] == "error" { + failures = append(failures, entry) } } - if failure == nil { - t.Fatalf("no error-level record; records=%+v", log.records) + if len(failures) != 1 { + t.Fatalf("error records = %d, want 1; log=%s", len(failures), data) + } + failure := failures[0] + details, ok := failure["details"].(map[string]any) + if !ok || details["code"] != "UV_EXEC_FAILED" || details["stage"] != "uv.verify" || + details["failureKind"] != "start_failed" || details["windowsError"] != float64(5) { + t.Fatalf("failure details = %#v, want uv execution diagnostics", failure["details"]) } - if failure.details["code"] == nil || failure.details["stage"] == nil { - t.Fatalf("failure record details = %+v, want code and stage", failure.details) + events := parseNDJSON(t, stdout.String()) + if failure["command"] != "bootstrap" || failure["operationId"] != events[0].object["operationId"] { + t.Fatalf("failure identity = %#v, want bootstrap and current operationId", failure) } } diff --git a/internal/cli/cli.go b/internal/cli/cli.go index 77dc794..42f5a27 100644 --- a/internal/cli/cli.go +++ b/internal/cli/cli.go @@ -153,9 +153,8 @@ type deps struct { io IO options options global globalOptions - // opLog 指向本次会话已打开的操作日志器（可能为 nil）。 - // 失败落盘要用它：命令失败的唯一出口 emitFailure 在会话层， - // 拿不到各命令自己开的 logger，靠这个绑定把两者接起来。 + // opLog 绑定命令的操作日志器；命令收尾后它可能已关闭。 + // 会话仅为曾开启操作日志的失败命令创建终态日志器，再通过此绑定记录最终失败。 opLog *workspaceLogBinding exitCode int } diff --git a/internal/cli/session.go b/internal/cli/session.go index fccefee..201e0a8 100644 --- a/internal/cli/session.go +++ b/internal/cli/session.go @@ -4,6 +4,7 @@ import ( "context" "errors" "fmt" + "io" "github.com/AUTO-MAS-Project/AUTO-MAS-Runtime/internal/logging" "github.com/AUTO-MAS-Project/AUTO-MAS-Runtime/internal/protocol" @@ -175,6 +176,28 @@ func runOperationSession( if panicked { telemetryState.addPanic(err, panicFrames) } + // 命令已关闭自己的日志器；终态使用独立 writer，才能记录包含清理错误的最终失败。 + // 只为已经开过日志的命令追加，避免早期失败创建原本不存在的受管目录。 + if deps.opLog.Get() != nil { + deps.opLog.Set(nil) + logContext, cancelLog := context.WithTimeout(context.WithoutCancel(ctx), m5TransactionCleanupTimeout) + defer cancelLog() + failureLogger, logErr := deps.options.workspaceLoggerFactory( + // 磁盘诊断已经在首次打开时写过 stderr，终态追加不重复播报。 + logContext, deps.global.layout, io.Discard, command, emitter.OperationID(), deps.options.clock, + ) + if logErr != nil { + writeDiagnostic(deps.io, logErr) + } else { + deps.opLog.Set(failureLogger) + defer func() { + deps.opLog.Set(nil) + if closeErr := failureLogger.Close(); closeErr != nil { + writeDiagnostic(deps.io, closeErr) + } + }() + } + } exitCode, telemetryState.terminalWritten = emitFailure(deps, emitter, stage, err) return exitCode } @@ -464,5 +487,7 @@ func recordOperationFailure( // 取消导致的失败同样要落盘，所以剥掉取消信号再写。 ctx, cancel := context.WithTimeout(context.WithoutCancel(ctx), m5TransactionCleanupTimeout) defer cancel() - _, _ = logger.Record(ctx, logging.LevelError, message, entry) + if _, err := logger.Record(ctx, logging.LevelError, message, entry); err != nil { + writeDiagnostic(deps.io, err) + } } diff --git a/internal/uv/bootstrap.go b/internal/uv/bootstrap.go index 7f3bd58..c040198 100644 --- a/internal/uv/bootstrap.go +++ b/internal/uv/bootstrap.go @@ -1024,11 +1024,16 @@ func wrapBootstrapError(stage protocol.Stage, err error) error { if errors.Is(err, context.Canceled) || errors.Is(err, context.DeadlineExceeded) { return err } + var details map[string]any + var detailed interface{ Details() map[string]any } + if errors.As(err, &detailed) { + details = detailed.Details() + } return newError( bootstrapErrorCode(err), stage, "uv 准备失败", - map[string]any{}, + details, err, ) } diff --git a/internal/uv/bootstrap_test.go b/internal/uv/bootstrap_test.go index f1c8c11..e17919d 100644 --- a/internal/uv/bootstrap_test.go +++ b/internal/uv/bootstrap_test.go @@ -63,6 +63,40 @@ func TestBootstrap_CacheHitAndVersionVerification(t *testing.T) { } } +func TestBootstrap_CachedExecutableFailurePreservesDiagnostics(t *testing.T) { + layout := newUVTestLayout(t) + artifact := testArtifact("cached archive") + executable, err := layout.UVExecutable(artifact.Version) + if err != nil { + t.Fatal(err) + } + if err := os.MkdirAll(filepath.Dir(executable), 0o700); err != nil { + t.Fatal(err) + } + if err := os.WriteFile(executable, []byte("fake uv"), 0o700); err != nil { + t.Fatal(err) + } + cause := errors.New("executable access denied") + checker := &fakeVersionChecker{err: newError( + protocol.CodeUVExecFailed, protocol.StageUVVerify, "uv 执行失败", + map[string]any{"failureKind": "start_failed", "windowsError": uint64(5)}, cause, + )} + bootstrapper := newTestBootstrapper(t, layout, artifact, &fakeDownloader{}, checker, nil, nil) + + _, err = bootstrapper.Ensure(t.Context(), testOperationID, testMirrorPolicy(t)) + var failure *Error + if !errors.As(err, &failure) || !errors.Is(err, cause) { + t.Fatalf("Ensure() error = %v, want original execution failure", err) + } + if failure.Code() != protocol.CodeUVExecFailed || failure.Stage() != protocol.StageUVVerify { + t.Fatalf("failure = %s/%s, want UV_EXEC_FAILED/uv.verify", failure.Code(), failure.Stage()) + } + details := failure.Details() + if details["failureKind"] != "start_failed" || details["windowsError"] != uint64(5) { + t.Fatalf("failure details = %#v, want start_failed and windowsError=5", details) + } +} + func TestBootstrap_ForwardsDownloadProgress(t *testing.T) { layout := newUVTestLayout(t) archiveBytes := makeUVArchive(t)