完善日志审计身份与致命错误落盘，补充三数据库清理验收

2026-09-08 22:53:20 +08:00 · 2026-09-08 22:53:20 +08:00 · b4337dca40
commit b4337dca40
parent b77b272a5e
10 changed files with 314 additions and 11 deletions
--- a/backend/controllers/login.go
+++ b/backend/controllers/login.go
@ -105,7 +105,7 @@ func loginSecurityFields(user *models.User) map[string]any {
 		"recoveryCodesConfigured": false,
 		"showRecoverySetupPrompt": false,
 		"showSecuritySetupPrompt": user != nil && user.SecuritySetupAcknowledged == 0,
-		"webAuthnEnabled": webAuthnRuntime() != nil,
+		"webAuthnEnabled":         webAuthnRuntime() != nil,
 	}
 	if user == nil || user.EffectiveRole() == access.RoleSuperAdmin {
 		return fields
@ -270,9 +270,18 @@ func Login(ctx *context.Context, w http.ResponseWriter, req *http.Request) {
 	for key, value := range loginSecurityFields(user) {
 		result[key] = value
 	}
+	setLoginAuditActor(ctx, user)
 	response.NewSuccessResponse(result).FPrint(w)
 }

+// setLoginAuditActor 只在完整登录成功后补充审计身份，不将待二次验证视为登录完成。
+func setLoginAuditActor(ctx *context.Context, user *models.User) {
+	ctx.UserID = user.ID
+	ctx.UserAccount = user.Account
+	ctx.UserName = user.Name
+	ctx.Role = user.EffectiveRole()
+}
+
 func Logout(ctx *context.Context, w http.ResponseWriter, req *http.Request) {
 	csrf.Clear(w, req, !config.DevelopmentMode)
 	if err := session.Instance.Destroy(ctx.Context); err != nil {
--- a/backend/controllers/login_verification.go
+++ b/backend/controllers/login_verification.go
@ -265,6 +265,7 @@ func completeLoginSession(ctx *context.Context, w http.ResponseWriter, req *http
 	for key, value := range loginSecurityFields(user) {
 		result[key] = value
 	}
+	setLoginAuditActor(ctx, user)
 	response.NewSuccessResponse(result).FPrint(w)
 }

--- a/backend/internal/app/app.go
+++ b/backend/internal/app/app.go
@ -14,7 +14,7 @@ import (
 )

 // Run 启动 Smail 主服务。
-func Run() error {
+func Run() (err error) {
 	if err := config.InitializeDeployment(config.ROOT_PATH); err != nil {
 		return err
 	}
@ -28,7 +28,7 @@ func Run() error {
 	if err != nil {
 		return fmt.Errorf("启动运行日志失败: %w", err)
 	}
-	defer runtimeLogs.Close()
+	defer finishRuntimeLogs(runtimeLogs, &err)
 	config.MaintainManagedSSLHistory()

 	build := buildinfo.Current()
@ -56,6 +56,19 @@ func Run() error {
 	return nil
 }

+// finishRuntimeLogs 在关闭日志文件前记录返回错误或异常，避免致命错误只留在控制台。
+func finishRuntimeLogs(writer *runtimelog.Writer, runErr *error) {
+	if recovered := recover(); recovered != nil {
+		*runErr = fmt.Errorf("服务启动异常: %v", recovered)
+	}
+	if *runErr != nil {
+		log.WithError(*runErr).Error("服务因致命错误停止")
+	}
+	if err := writer.Close(); err != nil {
+		log.WithError(err).Error("关闭运行日志失败")
+	}
+}
+
 // RunAndExit 执行主服务并在发生致命错误时退出。
 func RunAndExit() {
 	if err := Run(); err != nil {
--- a/backend/listen/http_server/operation_log.go
+++ b/backend/listen/http_server/operation_log.go
@ -14,7 +14,9 @@ import (
 // 仅记录明确的变更接口，不将 POST 列表查询误认为操作，也不复制请求或响应载荷。
 var loggedOperations = map[string]string{
 	"/api/login": "处理账号登录", "/api/logout": "退出登录",
-	"/api/user/create": "创建用户", "/api/user/edit": "编辑用户",
+	"/api/security/login/verify":          "完成登录二次验证",
+	"/api/security/webauthn/login/finish": "完成通行密钥登录验证",
+	"/api/user/create":                    "创建用户", "/api/user/edit": "编辑用户",
 	"/api/group/add": "创建分组", "/api/group/del": "删除分组",
 	"/api/email/del": "删除邮件", "/api/email/move": "移动邮件", "/api/email/read": "修改已读状态",
 	"/api/rule/add": "创建邮件规则", "/api/rule/update": "修改邮件规则", "/api/rule/del": "删除邮件规则",
--- a/docs/日志改造任务.md
+++ b/docs/日志改造任务.md
@ -15,13 +15,24 @@

 ## 实施状态

- [x] 已完成，等待复审：需求确认与修改前 Git 检查点；推送认证失败，未声称远程更新。
- [~] 进行中：三数据库兼容存储、30 天滚动清理及旧配置审计迁移。
- [ ] 未开始：操作及收发信记录接入。
- [~] 进行中：运行日志轮转、七天压缩、30 天清理及只读查询。
- [ ] 未开始：具体配置变更明细与脱敏。
- [ ] 未开始：日志管理界面及原审计界面优化。
- [ ] 未开始：隔离测试、最新构建部署及浏览器验收。
+- [✓] 复审通过：需求确认与修改前 Git 检查点，`5faadcd`、`b77b272` 已成功推送至 `smail/main`。
+- [x] 已完成，等待复审：三数据库兼容存储、30 天滚动清理及旧配置审计幂等迁移；SQLite 已真实执行，MySQL、PostgreSQL 等待专用连接验收。
+- [x] 已完成，等待复审：操作及收发信记录接入；登录完成的身份与二次验证入口补充审计。
+- [✓] 复审通过：运行日志日文件、七天压缩、边界日精确清理和压缩查询；损坏归档保留原文件；归档不阻塞当天已打开日志句柄追加。
+- [✓] 复审通过：具体配置变更明细、敏感字段脱敏及审计导出回归。
+- [x] 已完成，等待复审：日志管理页面，访问权限、筛选、短页回退、过期文件切换、请求竞态回归通过，尚待真实浏览器验收。
+- [~] 进行中：完整构建、同步最新部署包至 `yunx-test`、重启及浏览器验收。
+- [!] 暂缓或存在阻塞：MySQL、PostgreSQL 活库测试缺少本项目专用测试连接，不能用其他项目数据库替代。
+
+## 当前验证记录
+
+- 全量回归：`test-log/run-2026-09-08T14-40-12-728Z-20120`，前端 144 项、部署 4 项及后端全包通过。
+- 并发检测：`test-log/run-2026-09-08T14-44-59-839Z-25272`，运行日志与数据库日志包 `-race -count=1` 通过。
+- 补充修正后的全量回归：`test-log/run-2026-09-08T14-51-24-127Z-17952`，前端 144 项、部署 4 项及后端全包通过，包含完整登录审计身份及致命错误落盘测试。
+- MySQL、PostgreSQL 日志专项集成入口：`node test/run.mjs backend -v -run TestLogStoreServerDatabaseIntegration ./services/logstore`。需设置 `SMAIL_TEST_MYSQL_DSN`、`SMAIL_TEST_POSTGRES_DSN`，只创建连接私有临时日志表，不改动既有业务表；测试连接断线后禁止自动重连。当前变量未设置，相关活库测试跳过。
+- 启动补清理，之后每小时执行，数据库每批最多删除 1000 条；查询立即应用最近 30×24 小时窗口。物理清理存在调度间隔，不声称每秒即时删除。
+- 运行日志文件名采用 UTC 日期，每条记录含明确时区；后台显示本地时间。已压缩文件也按记录时间清理，压缩不重新计时。
+- 模拟部署启动器的控制台诊断写入 `test-log/service-launch`，不在 `yunx-test/log` 重复生成散乱的启动文件；旧文件保留。

 ## 验收边界

--- a/test/backend/app_runtime_log_test.go
+++ b/test/backend/app_runtime_log_test.go
@ -0,0 +1,43 @@
+package app
+
+import (
+	"errors"
+	"os"
+	"path/filepath"
+	"strings"
+	"testing"
+
+	"git.pcux.cn/xuans/Smail/services/runtimelog"
+	log "github.com/sirupsen/logrus"
+)
+
+func TestFatalErrorIsLoggedBeforeRuntimeClose(t *testing.T) {
+	for _, panics := range []bool{false, true} {
+		root := t.TempDir()
+		previousHooks := log.StandardLogger().ReplaceHooks(make(log.LevelHooks))
+		writer, err := runtimelog.Start(root)
+		if err != nil {
+			log.StandardLogger().ReplaceHooks(previousHooks)
+			t.Fatal(err)
+		}
+		err = func() (runErr error) {
+			defer finishRuntimeLogs(writer, &runErr)
+			if panics {
+				panic("fatal-probe")
+			}
+			return errors.New("fatal-probe")
+		}()
+		log.StandardLogger().ReplaceHooks(previousHooks)
+		if err == nil || !strings.Contains(err.Error(), "fatal-probe") {
+			t.Fatalf("fatal error lost: %v", err)
+		}
+		files, err := filepath.Glob(filepath.Join(root, "log", "运行日志", "runtime-*.log"))
+		if err != nil || len(files) != 1 {
+			t.Fatalf("missing runtime log: %v", err)
+		}
+		data, err := os.ReadFile(files[0])
+		if err != nil || !strings.Contains(string(data), "fatal-probe") {
+			t.Fatal("fatal error was not written before close")
+		}
+	}
+}
--- a/test/backend/log_store_integration_test.go
+++ b/test/backend/log_store_integration_test.go
@ -0,0 +1,124 @@
+package logstore
+
+import (
+	"context"
+	"database/sql"
+	"database/sql/driver"
+	"errors"
+	"fmt"
+	"os"
+	"strings"
+	"sync"
+	"testing"
+	"time"
+
+	"git.pcux.cn/xuans/Smail/db/migration"
+	"git.pcux.cn/xuans/Smail/utils/logpolicy"
+	mysql "github.com/go-sql-driver/mysql"
+	"github.com/lib/pq"
+)
+
+// 禁止 database/sql 在断线后重建连接，以免临时表消失后误访问同名的永久表。
+type logTestConnector struct {
+	driver.Connector
+	mu   sync.Mutex
+	used bool
+}
+
+func (c *logTestConnector) Connect(ctx context.Context) (driver.Conn, error) {
+	c.mu.Lock()
+	defer c.mu.Unlock()
+	if c.used {
+		return nil, errors.New("temporary log test connection cannot reconnect")
+	}
+	c.used = true
+	return c.Connector.Connect(ctx)
+}
+
+// 使用连接私有的临时表，关闭连接自动回收，不迁移或清空任何既有业务表。
+func TestLogStoreServerDatabaseIntegration(t *testing.T) {
+	for _, test := range []struct {
+		name, driver, environment string
+		dialect                   migration.Dialect
+	}{
+		{"mysql", "mysql", "SMAIL_TEST_MYSQL_DSN", migration.DialectMySQL},
+		{"postgres", "postgres", "SMAIL_TEST_POSTGRES_DSN", migration.DialectPostgres},
+	} {
+		t.Run(test.name, func(t *testing.T) {
+			dsn := strings.TrimSpace(os.Getenv(test.environment))
+			if dsn == "" {
+				t.Skip(test.environment + " is not set")
+			}
+			var connector driver.Connector
+			var err error
+			if test.dialect == migration.DialectMySQL {
+				configuration, parseErr := mysql.ParseDSN(dsn)
+				if parseErr != nil {
+					t.Fatal("test database connection configuration is invalid")
+				}
+				connector, err = mysql.NewConnector(configuration)
+			} else {
+				connector, err = pq.NewConnector(dsn)
+			}
+			if err != nil {
+				t.Fatal("test database connection configuration is invalid")
+			}
+			database := sql.OpenDB(&logTestConnector{Connector: connector})
+			defer database.Close()
+			database.SetMaxOpenConns(1)
+			database.SetMaxIdleConns(1)
+			ctx, cancel := context.WithTimeout(context.Background(), 90*time.Second)
+			defer cancel()
+			if err := database.PingContext(ctx); err != nil {
+				t.Fatal("dedicated test database is unavailable")
+			}
+			migrations := migration.DefaultMigrations()
+			for _, statement := range migrations[len(migrations)-1].StatementsFor(test.dialect) {
+				if strings.HasPrefix(statement, "CREATE TABLE IF NOT EXISTS ") {
+					statement = strings.Replace(statement, "CREATE TABLE IF NOT EXISTS ", "CREATE TEMPORARY TABLE ", 1)
+				}
+				if _, err := database.ExecContext(ctx, statement); err != nil {
+					t.Fatal("temporary log schema creation failed")
+				}
+			}
+			store, err := New(database, test.dialect)
+			if err != nil {
+				t.Fatal(err)
+			}
+			now := time.Now().UTC()
+			cutoff := logpolicy.Cutoff(now)
+			store.now = func() time.Time { return now.Add(-logpolicy.Retention) }
+			for _, kind := range []string{"operation", "config", "mail"} {
+				for index := 0; index < 1003; index++ {
+					at := cutoff.Add(-time.Nanosecond)
+					if index >= 1001 {
+						at = cutoff.Add(time.Duration(index - 1001))
+					}
+					entry := Entry{ID: fmt.Sprintf("%s-%d", kind, index), CreatedAt: at, Kind: kind, ActorID: "42", Action: "兼容验证", Result: "success", Payload: []byte(`{"message":"中文日志"}`)}
+					if err := store.Write(ctx, entry); err != nil {
+						t.Fatal(err)
+					}
+					if index == 1002 {
+						if err := store.Write(ctx, entry); err != nil {
+							t.Fatal("idempotent replay failed")
+						}
+					}
+				}
+			}
+			store.now = func() time.Time { return now }
+			for _, kind := range []string{"operation", "config", "mail"} {
+				items, err := store.Query(ctx, Query{Kind: kind, ActorID: "42"})
+				if err != nil || len(items) != 2 || items[0].Action != "兼容验证" {
+					t.Fatalf("query or retention failed: kind=%s count=%d err=%v", kind, len(items), err)
+				}
+			}
+			deleted, err := store.Cleanup(ctx, now)
+			if err != nil || deleted != 3003 {
+				t.Fatalf("batch cleanup failed: deleted=%d err=%v", deleted, err)
+			}
+			if deleted, err := store.Cleanup(ctx, now); err != nil || deleted != 0 {
+				t.Fatalf("repeated cleanup failed: deleted=%d err=%v", deleted, err)
+			}
+		})
+	}
+}
--- a/test/backend/login_audit_test.go
+++ b/test/backend/login_audit_test.go
@ -0,0 +1,38 @@
+package controllers
+
+import (
+	"context"
+	"encoding/json"
+	"net/http/httptest"
+	"testing"
+
+	"git.pcux.cn/xuans/Smail/config"
+	"git.pcux.cn/xuans/Smail/dto/response"
+	"git.pcux.cn/xuans/Smail/models"
+	"git.pcux.cn/xuans/Smail/services/access"
+	"git.pcux.cn/xuans/Smail/session"
+	appcontext "git.pcux.cn/xuans/Smail/utils/context"
+	"github.com/alexedwards/scs/v2"
+)
+
+func TestCompletedLoginSetsAuditActor(t *testing.T) {
+	previousConfig, previousSession := config.Instance, session.Instance
+	t.Cleanup(func() { config.Instance, session.Instance = previousConfig, previousSession })
+	config.Instance = &config.Config{Domain: "example.test"}
+	session.Instance = scs.New()
+	loaded, err := session.Instance.Load(context.Background(), "")
+	if err != nil {
+		t.Fatal(err)
+	}
+	ctx := &appcontext.Context{Context: loaded}
+	request := httptest.NewRequest("POST", "https://example.test/api/security/login/verify", nil).WithContext(loaded)
+	writer := httptest.NewRecorder()
+	completeLoginSession(ctx, writer, request, &models.User{ID: 42, Account: "audit-probe", Role: string(access.RoleSuperAdmin)})
+	var result response.Response
+	if err := json.Unmarshal(writer.Body.Bytes(), &result); err != nil {
+		t.Fatal(err)
+	}
+	if result.ErrorNo != 0 || ctx.UserID != 42 || ctx.UserAccount != "audit-probe" || ctx.Role != access.RoleSuperAdmin {
+		t.Fatalf("completed login lost audit actor: code=%d id=%d role=%s", result.ErrorNo, ctx.UserID, ctx.Role)
+	}
+}
--- a/test/backend/operation_log_test.go
+++ b/test/backend/operation_log_test.go
@ -0,0 +1,58 @@
+package http_server
+
+import (
+	"context"
+	"database/sql"
+	"encoding/json"
+	"net/http/httptest"
+	"path/filepath"
+	"testing"
+
+	"git.pcux.cn/xuans/Smail/db/migration"
+	"git.pcux.cn/xuans/Smail/dto/response"
+	"git.pcux.cn/xuans/Smail/services/access"
+	"git.pcux.cn/xuans/Smail/services/logstore"
+	appcontext "git.pcux.cn/xuans/Smail/utils/context"
+	_ "modernc.org/sqlite"
+)
+
+func TestOperationLogUsesCompletedIdentityWithoutSensitivePayload(t *testing.T) {
+	database, err := sql.Open("sqlite", filepath.Join(t.TempDir(), "operations.db"))
+	if err != nil {
+		t.Fatal(err)
+	}
+	defer database.Close()
+	database.SetMaxOpenConns(1)
+	migrations := migration.DefaultMigrations()
+	for _, statement := range migrations[len(migrations)-1].StatementsFor(migration.DialectSQLite) {
+		if _, err := database.Exec(statement); err != nil {
+			t.Fatal(err)
+		}
+	}
+	store, err := logstore.New(database, migration.DialectSQLite)
+	if err != nil {
+		t.Fatal(err)
+	}
+	runtime := logstore.Start(store)
+	defer runtime.Stop()
+	for _, path := range []string{"/api/v1/login", "/api/v1/security/login/verify", "/api/v1/security/webauthn/login/finish"} {
+		ctx := &appcontext.Context{}
+		writer, finish := operationLog(ctx, httptest.NewRequest("POST", path, nil), httptest.NewRecorder())
+		ctx.UserID, ctx.UserAccount, ctx.Role = 42, "audit-probe", access.RoleSuperAdmin
+		response.NewSuccessResponse(map[string]string{"token": "must-not-store"}).FPrint(writer)
+		finish()
+	}
+	entries, err := store.Query(context.Background(), logstore.Query{Kind: "operation", ActorID: "42"})
+	if err != nil || len(entries) != 3 {
+		t.Fatalf("missing completed login records: %d, %v", len(entries), err)
+	}
+	for _, entry := range entries {
+		var payload map[string]any
+		if err := json.Unmarshal(entry.Payload, &payload); err != nil {
+			t.Fatal(err)
+		}
+		if entry.Result != "success" || payload["actorName"] != "audit-probe" || len(payload) != 3 {
+			t.Fatalf("incorrect or excessive audit metadata: %+v", payload)
+		}
+	}
+}
--- a/test/run.mjs
+++ b/test/run.mjs
@ -49,8 +49,12 @@ if ((suite === 'all' || suite === 'backend') && result === 0) {
  const args = extra[0] === '--' ? extra.slice(1) : extra
  // 独立回归源码集中放在 test/backend，通过 overlay 保留同包测试语义。
  const replacements = {
+    'backend/internal/app/runtime_log_test.go': 'test/backend/app_runtime_log_test.go',
+    'backend/listen/http_server/operation_log_test.go': 'test/backend/operation_log_test.go',
+    'backend/controllers/login_audit_test.go': 'test/backend/login_audit_test.go',
    'backend/controllers/logs_api_test.go': 'test/backend/logs_api_test.go',
    'backend/services/logstore/log_store_test.go': 'test/backend/log_store_test.go',
+    'backend/services/logstore/log_store_integration_test.go': 'test/backend/log_store_integration_test.go',
    'backend/services/runtimelog/runtime_logs_test.go': 'test/backend/runtime_logs_test.go',
    'backend/db/migration/log_migration_test.go': 'test/backend/log_migration_test.go',
    'backend/config/audit_changes_test.go': 'test/backend/audit_changes_test.go',