fix: 保留 uv 执行诊断并补齐失败日志 (T5.17)

doc/current/M5/计划-T5.17-uv执行失败诊断.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，
+   不直推主分支或发版。

doc/current/M5/设计-T5.17-uv执行失败诊断.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 确认。

doc/任务拆分.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 验收。
 

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)
 	}
 }
 

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
 }

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)
+	}
 }

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,
 	)
 }

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)