diff --git a/backend/internal/auth/email.go b/backend/internal/auth/email.go index 3277abd4a..2dc17ac78 100644 --- a/backend/internal/auth/email.go +++ b/backend/internal/auth/email.go @@ -5,16 +5,20 @@ import ( "crypto/rand" "crypto/sha256" "crypto/tls" + "encoding/base64" "encoding/hex" "encoding/json" "errors" "fmt" "log" + "log/slog" "math/big" "mime" "net" "net/mail" "net/smtp" + "regexp" + "sort" "strconv" "strings" "time" @@ -425,25 +429,34 @@ func resolveEmailSender(value EmailSettingValue, brandName string) EmailSettingV return value } -func sendSMTPMail(setting EmailSettingValue, recipient string, subject string, body string) error { +func sendSMTPMail(setting EmailSettingValue, recipient string, subject string, body string) (err error) { + stage := "connect" + defer func() { + if err != nil { + err = fmt.Errorf("smtp %s: %w", stage, err) + } + }() address := net.JoinHostPort(setting.Host, strconv.Itoa(setting.Port)) tlsConfig := &tls.Config{ServerName: setting.Host, MinVersion: tls.VersionTLS12} dialer := &net.Dialer{Timeout: 12 * time.Second} var client *smtp.Client - var err error if setting.Encryption == "tls" { + stage = "connect_tls" connection, dialErr := tls.DialWithDialer(dialer, "tcp", address, tlsConfig) if dialErr != nil { return dialErr } + stage = "greeting" client, err = smtp.NewClient(connection, setting.Host) } else { connection, dialErr := dialer.Dial("tcp", address) if dialErr != nil { return dialErr } + stage = "greeting" client, err = smtp.NewClient(connection, setting.Host) if err == nil && setting.Encryption == "starttls" { + stage = "starttls" err = client.StartTLS(tlsConfig) } } @@ -452,37 +465,74 @@ func sendSMTPMail(setting EmailSettingValue, recipient string, subject string, b } defer client.Close() if setting.Username != "" { + stage = "auth" if err := client.Auth(smtp.PlainAuth("", setting.Username, setting.Password, setting.Host)); err != nil { return err } } + stage = "mail_from" if err := client.Mail(setting.FromEmail); err != nil { return err } + stage = "rcpt_to" if err := client.Rcpt(recipient); err != nil { return err } + stage = "data" wc, err := client.Data() if err != nil { return err } from := mail.Address{Name: setting.FromName, Address: setting.FromEmail} message := fmt.Sprintf("From: %s\r\nTo: %s\r\nSubject: %s\r\nMIME-Version: 1.0\r\nContent-Type: text/plain; charset=UTF-8\r\n\r\n%s", from.String(), recipient, mime.QEncoding.Encode("UTF-8", subject), body) + stage = "write_body" if _, err := wc.Write([]byte(message)); err != nil { _ = wc.Close() return err } + stage = "finish_data" if err := wc.Close(); err != nil { return err } + stage = "quit" return client.Quit() } func (s *Service) deliverEmail(setting EmailSettingValue, recipient string, subject string, body string) error { + var err error if s.mailSender != nil { - return s.mailSender(setting, recipient, subject, body) + err = s.mailSender(setting, recipient, subject, body) + } else { + err = sendSMTPMail(setting, recipient, subject, body) } - return sendSMTPMail(setting, recipient, subject, body) + if err != nil { + slog.Error("smtp email delivery failed", + "host", setting.Host, "port", setting.Port, "encryption", setting.Encryption, + "recipient", maskedEmail(recipient), "error", smtpLogError(err, setting, recipient, subject, body)) + } + return err +} + +var emailCodeLogPattern = regexp.MustCompile(`[0-9]{6}`) + +func smtpLogError(err error, setting EmailSettingValue, recipient, subject, body string) string { + // SMTP replies can echo credentials, addresses or message content. Redact + // those values before logging while preserving the status and failure detail. + secrets := []string{setting.Password, setting.Username, setting.FromEmail, recipient, subject, body, + "\x00" + setting.Username + "\x00" + setting.Password} + secrets = append(secrets, emailCodeLogPattern.FindAllString(body, -1)...) + values := make([]string, 0, len(secrets)*2) + for _, secret := range secrets { + if secret != "" { + values = append(values, secret, base64.StdEncoding.EncodeToString([]byte(secret))) + } + } + sort.Slice(values, func(i, j int) bool { return len(values[i]) > len(values[j]) }) + pairs := make([]string, 0, len(values)*2) + for _, value := range values { + pairs = append(pairs, value, "[redacted]") + } + return strings.NewReplacer(pairs...).Replace(err.Error()) } func randomNumericCode(length int) (string, error) { diff --git a/backend/internal/auth/email_logging_test.go b/backend/internal/auth/email_logging_test.go new file mode 100644 index 000000000..4415b3410 --- /dev/null +++ b/backend/internal/auth/email_logging_test.go @@ -0,0 +1,130 @@ +package auth + +import ( + "bufio" + "bytes" + "encoding/base64" + "encoding/json" + "errors" + "fmt" + "log/slog" + "net" + "net/textproto" + "strings" + "testing" + "time" +) + +func captureSMTPLogs(t *testing.T) *bytes.Buffer { + t.Helper() + var output bytes.Buffer + previous := slog.Default() + slog.SetDefault(slog.New(slog.NewJSONHandler(&output, &slog.HandlerOptions{Level: slog.LevelInfo}))) + t.Cleanup(func() { slog.SetDefault(previous) }) + return &output +} + +func TestEmailDeliveryLogsFailureWithoutSecrets(t *testing.T) { + output := captureSMTPLogs(t) + setting := EmailSettingValue{Host: "smtp.example.com", Port: 587, Encryption: "starttls", Username: "smtp-user", Password: "smtp-secret", FromEmail: "sender@example.com"} + recipient, subject, body := "reader@example.com", "Verification", "Your verification code is 123456." + secrets := []string{setting.Username, setting.Password, setting.FromEmail, recipient, subject, body, "123456", "\x00" + setting.Username + "\x00" + setting.Password} + detail := "535 5.7.8 Authentication credentials invalid" + for _, secret := range secrets { + detail += " " + secret + " " + base64.StdEncoding.EncodeToString([]byte(secret)) + } + deliveryErr := errors.New(detail) + svc := New(nil, nil, func(EmailSettingValue, string, string, string) error { return deliveryErr }) + if err := svc.deliverEmail(setting, recipient, subject, body); err != deliveryErr { + t.Fatalf("delivery error was changed: %v", err) + } + var entry struct { + Level, Msg, Host, Encryption, Recipient, Error string + Port int + } + if err := json.Unmarshal(output.Bytes(), &entry); err != nil { + t.Fatalf("expected exactly one JSON log entry: %v", err) + } + if entry.Level != "ERROR" || entry.Msg != "smtp email delivery failed" || entry.Host != setting.Host || entry.Port != setting.Port || entry.Encryption != setting.Encryption || entry.Recipient != maskedEmail(recipient) { + t.Fatalf("missing SMTP log context: %+v", entry) + } + if !strings.Contains(entry.Error, "535 5.7.8 Authentication credentials invalid") { + t.Fatalf("SMTP failure detail was lost: %q", entry.Error) + } + for _, secret := range secrets { + if strings.Contains(entry.Error, secret) || strings.Contains(entry.Error, base64.StdEncoding.EncodeToString([]byte(secret))) { + t.Fatalf("SMTP log contains sensitive value %q", secret) + } + } + svc.SetMailSender(func(EmailSettingValue, string, string, string) error { return nil }) + output.Reset() + if err := svc.deliverEmail(setting, recipient, subject, body); err != nil || output.Len() != 0 { + t.Fatalf("successful delivery produced an error/log: %v %s", err, output.String()) + } +} + +func TestSMTPDeliveryLogsProtocolFailureStage(t *testing.T) { + type exchange struct{ command, reply string } + for _, test := range []struct { + name, encryption, username, stage, detail string + exchanges []exchange + }{ + {name: "greeting", stage: "greeting", detail: "554 SMTP service unavailable", exchanges: []exchange{{"", "554 SMTP service unavailable\r\n"}}}, + {name: "starttls", encryption: "starttls", stage: "starttls", detail: "454 TLS temporarily unavailable", exchanges: []exchange{ + {"", "220 localhost\r\n"}, {"EHLO ", "250-localhost\r\n250 STARTTLS\r\n"}, {"STARTTLS", "454 TLS temporarily unavailable\r\n"}, + }}, + {name: "auth", username: "smtp-user", stage: "auth", detail: "535 5.7.8 Authentication credentials invalid", exchanges: []exchange{ + {"", "220 localhost\r\n"}, {"EHLO ", "250-localhost\r\n250 AUTH PLAIN\r\n"}, {"AUTH PLAIN ", "535 5.7.8 Authentication credentials invalid\r\n"}, + }}, + {name: "recipient", stage: "rcpt_to", detail: "550 5.1.1 Recipient rejected", exchanges: []exchange{ + {"", "220 localhost\r\n"}, {"EHLO ", "250 localhost\r\n"}, {"MAIL FROM:", "250 OK\r\n"}, {"RCPT TO:", "550 5.1.1 Recipient rejected\r\n"}, + }}, + } { + t.Run(test.name, func(t *testing.T) { + output := captureSMTPLogs(t) + listener, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + t.Cleanup(func() { listener.Close() }) + done := make(chan error, 1) + go func() { + conn, err := listener.Accept() + if err != nil { + done <- err + return + } + defer conn.Close() + conn.SetDeadline(time.Now().Add(3 * time.Second)) + reader := bufio.NewReader(conn) + for _, step := range test.exchanges { + if step.command != "" { + line, err := reader.ReadString('\n') + if err != nil || !strings.HasPrefix(line, step.command) { + done <- fmt.Errorf("expected command %q, got %q: %v", step.command, line, err) + return + } + } + if _, err := fmt.Fprint(conn, step.reply); err != nil { + done <- err + return + } + } + done <- nil + }() + setting := EmailSettingValue{Host: "127.0.0.1", Port: listener.Addr().(*net.TCPAddr).Port, Encryption: test.encryption, Username: test.username, Password: "smtp-secret", FromEmail: "sender@example.com"} + err = New(nil, nil, nil).deliverEmail(setting, "reader@example.com", "Verification", "Your code is 123456.") + if serverErr := <-done; serverErr != nil { + t.Fatal(serverErr) + } + var reply *textproto.Error + if err == nil || !strings.HasPrefix(err.Error(), "smtp "+test.stage+": ") || !errors.As(err, &reply) || fmt.Sprintf("%d %s", reply.Code, reply.Msg) != test.detail { + t.Fatalf("expected SMTP stage and reply, got %v", err) + } + var entry struct{ Error string } + if jsonErr := json.Unmarshal(output.Bytes(), &entry); jsonErr != nil || entry.Error != err.Error() { + t.Fatalf("missing detailed failure log: %s", output.String()) + } + }) + } +} diff --git a/backend/internal/auth/password_reset.go b/backend/internal/auth/password_reset.go index 3543cee86..8dad0e34f 100644 --- a/backend/internal/auth/password_reset.go +++ b/backend/internal/auth/password_reset.go @@ -80,7 +80,6 @@ func (s *Service) SendPasswordResetEmailCode(rawEmail string) error { if cleanupErr := s.repo.DeleteEmailVerificationCode(record.ID); cleanupErr != nil { log.Printf("password reset email cleanup failed: recipient=%s error=%v", maskedEmail(email), cleanupErr) } - log.Printf("password reset email delivery failed: recipient=%s error=%v", maskedEmail(email), err) return nil } if cleanupErr := s.repo.DeleteExpiredEmailVerificationCodes(now.Add(-24 * time.Hour)); cleanupErr != nil { diff --git a/docs/content/docs/backend/local-development.mdx b/docs/content/docs/backend/local-development.mdx index 36165fd3e..d94b3913e 100644 --- a/docs/content/docs/backend/local-development.mdx +++ b/docs/content/docs/backend/local-development.mdx @@ -5,6 +5,20 @@ description: 在宿主机启动影策前后端开发服务 # 本地开发 +## SMTP 邮件故障日志 + +注册、登录、绑定邮箱和密码找回的邮件投递失败统一输出 `ERROR` 级别的 `smtp email delivery failed` 后端日志。日志包含 `host`、`port`、`encryption`、脱敏 `recipient` 和 `error`,默认 `CANVAS_LOG_LEVEL=info` 即可看到,无需开启 debug。 + +`error` 保留 SMTP 状态码和服务器错误说明,并标记失败步骤:`connect` / `connect_tls`(连接)、`greeting`(服务器欢迎响应)、`starttls`、`auth`、`mail_from`、`rcpt_to`、`data`、`write_body`、`finish_data` 或 `quit`。日志不主动记录账号、密码、邮件标题、正文或验证码,并对错误中回显的这些值及其 Base64 编码做脱敏。对外 API 继续使用原有通用错误响应。 + +宿主机开发查看运行后端的终端;Docker 查看实际使用的 Compose 文件中的 `backend` 服务,例如: + +```bash +docker compose -f docker-compose.deploy.yml logs --since=15m -f backend +``` + +本地构建和热更新开发分别将文件名换成 `docker-compose.local.yml` 或 `docker-compose.dev.yml`。代码修改后需要运行新构建的后端,旧容器不会自动增加这些日志。 + ## Compose 公网资源地址 `docker-compose.yml`、`docker-compose.dev.yml`、`docker-compose.local.yml`、`docker-compose.server.yml` 和 `docker-compose.deploy.yml` 均将 `.env` 中的 `CANVAS_PUBLIC_BASE_URL` 传入后端。使用本地文件存储且上游模型需要读取参考素材时,将它设为上游能访问的 HTTPS 站点根地址(例如 `https://canvas.example.com`,不要附加 `/api`);存储设置中的公网访问地址优先于该环境变量。 diff --git a/docs/content/docs/progress/pending-test.mdx b/docs/content/docs/progress/pending-test.mdx index 52ca370d7..0fef029a3 100644 --- a/docs/content/docs/progress/pending-test.mdx +++ b/docs/content/docs/progress/pending-test.mdx @@ -24,6 +24,11 @@ description: 当前项目已实现功能的手工验证清单与未确认边界 - [x] 专项测试覆盖来源/目标 handle 放错节点、镜头编号误用、缺少 row 前缀、错误回执模板方向、普通连线与行绑定并存,以及重复行绑定仍拒绝;工具 schema 体积检查通过。 - [x] 用户已在本地验证镜头绑定可用;自动化测试不调用外部模型,不修改实际创作画布。 - [ ] 上游合并后验证新会话沿用正确绑定方向,错误调用不会被误报为成功。 +## SMTP 邮件故障日志 + +- 已实现:所有邮件投递入口统一记录详细后端错误,标记 SMTP 失败步骤,并隐藏错误回显中的账号、密码、邮箱、正文和验证码;不改变公开 API 响应。 +- [x] 专项测试通过:本地 SMTP 服务模拟欢迎响应、STARTTLS、认证和收件人拒绝;验证日志上下文、错误链保留、敏感值脱敏、成功时不记录失败日志,并回归密码找回流程。 +- [ ] 使用实际 SMTP 配置分别触发连接、TLS、认证和收件人失败,确认 `backend` 日志保留具体错误且无敏感信息;覆盖注册、登录、绑定邮箱和密码找回。 ## 复制生图节点后节点消失