fix(auth): SMTP 邮件 - 增加详细失败日志与敏感信息脱敏
This commit is contained in:
1 parent
5f322f2f5e
commit
0aa86f5f17
5 files changed
+204
-5
No files matched your search
@@ -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) {
|
||||
|
||||
@@ -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())
|
||||
}
|
||||
})
|
||||
}
|
||||
}
|
||||
@@ -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 {
|
||||
|
||||
Reference in new issue
Block a user