debug: add notification path logging for beta investigation

Add slog.Info/Debug logs to notifyBalanceLow, notifyAccountQuota,
CheckBalanceAfterDeduction, and sendEmails to diagnose why balance
and quota notifications are not being sent in beta environment.
This commit is contained in:
erio
2026-04-13 16:20:07 +08:00
parent 49131efb42
commit c6a9da4ea9
3 changed files with 54 additions and 1 deletions
+1 -1
View File
@@ -1 +1 @@
0.1.110.25
0.1.110.26
@@ -65,14 +65,21 @@ func resolveBalanceThreshold(threshold float64, thresholdType string, totalRecha
// Notification is sent only on first crossing: oldBalance >= threshold && newBalance < threshold.
func (s *BalanceNotifyService) CheckBalanceAfterDeduction(ctx context.Context, user *User, oldBalance, cost float64) {
if user == nil || s.emailService == nil || s.settingRepo == nil {
slog.Debug("CheckBalanceAfterDeduction: skipped (nil check)",
"user_nil", user == nil,
"email_svc_nil", s.emailService == nil,
"setting_repo_nil", s.settingRepo == nil,
)
return
}
if !user.BalanceNotifyEnabled {
slog.Debug("CheckBalanceAfterDeduction: user notify disabled", "user_id", user.ID)
return
}
globalEnabled, globalThreshold := s.getBalanceNotifyConfig(ctx)
if !globalEnabled {
slog.Info("CheckBalanceAfterDeduction: global notify disabled", "user_id", user.ID)
return
}
@@ -82,18 +89,33 @@ func (s *BalanceNotifyService) CheckBalanceAfterDeduction(ctx context.Context, u
threshold = *user.BalanceNotifyThreshold
}
if threshold <= 0 {
slog.Debug("CheckBalanceAfterDeduction: threshold <= 0", "user_id", user.ID, "threshold", threshold)
return
}
effectiveThreshold := resolveBalanceThreshold(threshold, user.BalanceNotifyThresholdType, user.TotalRecharged)
if effectiveThreshold <= 0 {
slog.Debug("CheckBalanceAfterDeduction: effective threshold <= 0", "user_id", user.ID)
return
}
newBalance := oldBalance - cost
slog.Info("CheckBalanceAfterDeduction: crossing check",
"user_id", user.ID,
"old_balance", oldBalance,
"new_balance", newBalance,
"effective_threshold", effectiveThreshold,
"crossed", oldBalance >= effectiveThreshold && newBalance < effectiveThreshold,
)
if oldBalance >= effectiveThreshold && newBalance < effectiveThreshold {
siteName := s.getSiteName(ctx)
recipients := s.collectBalanceNotifyRecipients(user)
slog.Info("CheckBalanceAfterDeduction: sending notification",
"user_id", user.ID,
"recipients", recipients,
"new_balance", newBalance,
"threshold", effectiveThreshold,
)
go func() {
defer func() {
if r := recover(); r != nil {
@@ -328,11 +350,17 @@ func (s *BalanceNotifyService) collectBalanceNotifyRecipients(user *User) []stri
// sendEmails sends an email to all recipients with shared timeout and error logging.
func (s *BalanceNotifyService) sendEmails(recipients []string, subject, body string, logAttrs ...any) {
if len(recipients) == 0 {
slog.Warn("sendEmails: no recipients", "subject", subject)
return
}
for _, to := range recipients {
ctx, cancel := context.WithTimeout(context.Background(), emailSendTimeout)
if err := s.emailService.SendEmail(ctx, to, subject, body); err != nil {
attrs := append([]any{"to", to, "error", err}, logAttrs...)
slog.Error("failed to send notification", attrs...)
} else {
slog.Info("notification email sent successfully", "to", to, "subject", subject)
}
cancel()
}
@@ -7538,10 +7538,24 @@ func finalizePostUsageBilling(p *postUsageBillingParams, deps *billingDeps, resu
// to reconstruct oldBalance, avoiding stale Redis reads and concurrent-deduction races.
func notifyBalanceLow(p *postUsageBillingParams, deps *billingDeps, result *UsageBillingApplyResult) {
if p.IsSubscriptionBill || p.Cost.ActualCost <= 0 || p.User == nil || deps.balanceNotifyService == nil {
slog.Debug("notifyBalanceLow: skipped",
"is_subscription", p.IsSubscriptionBill,
"actual_cost", p.Cost.ActualCost,
"user_nil", p.User == nil,
"service_nil", deps.balanceNotifyService == nil,
)
return
}
oldBalance := resolveOldBalance(p, result)
slog.Info("notifyBalanceLow: calling CheckBalanceAfterDeduction",
"user_id", p.User.ID,
"old_balance", oldBalance,
"cost", p.Cost.ActualCost,
"notify_enabled", p.User.BalanceNotifyEnabled,
"threshold", p.User.BalanceNotifyThreshold,
"result_has_new_balance", result != nil && result.NewBalance != nil,
)
deps.balanceNotifyService.CheckBalanceAfterDeduction(context.Background(), p.User, oldBalance, p.Cost.ActualCost)
}
@@ -7560,6 +7574,12 @@ func resolveOldBalance(p *postUsageBillingParams, result *UsageBillingApplyResul
// to avoid a separate DB read that may see stale or concurrently-modified data.
func notifyAccountQuota(p *postUsageBillingParams, deps *billingDeps, result *UsageBillingApplyResult) {
if p.Cost.TotalCost <= 0 || p.Account == nil || !p.Account.IsAPIKeyOrBedrock() || deps.balanceNotifyService == nil {
slog.Debug("notifyAccountQuota: skipped",
"total_cost", p.Cost.TotalCost,
"account_nil", p.Account == nil,
"is_apikey_or_bedrock", p.Account != nil && p.Account.IsAPIKeyOrBedrock(),
"service_nil", deps.balanceNotifyService == nil,
)
return
}
accountCost := p.Cost.TotalCost * p.AccountRateMultiplier
@@ -7567,6 +7587,11 @@ func notifyAccountQuota(p *postUsageBillingParams, deps *billingDeps, result *Us
if result != nil {
quotaState = result.QuotaState
}
slog.Info("notifyAccountQuota: calling CheckAccountQuotaAfterIncrement",
"account_id", p.Account.ID,
"account_cost", accountCost,
"has_quota_state", quotaState != nil,
)
deps.balanceNotifyService.CheckAccountQuotaAfterIncrement(context.Background(), p.Account, accountCost, quotaState)
}