payment_fulfillment.go 30 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887
  1. package service
  2. import (
  3. "context"
  4. "encoding/json"
  5. "errors"
  6. "fmt"
  7. "log/slog"
  8. "math"
  9. "strconv"
  10. "strings"
  11. "time"
  12. "entgo.io/ent/dialect"
  13. dbent "github.com/Wei-Shaw/sub2api/ent"
  14. "github.com/Wei-Shaw/sub2api/ent/paymentauditlog"
  15. "github.com/Wei-Shaw/sub2api/ent/paymentorder"
  16. "github.com/Wei-Shaw/sub2api/internal/payment"
  17. infraerrors "github.com/Wei-Shaw/sub2api/internal/pkg/errors"
  18. )
  19. // ErrOrderNotFound is returned by HandlePaymentNotification when the webhook
  20. // references an out_trade_no that does not exist in our DB. Callers (webhook
  21. // handlers) should treat this as a terminal, non-retryable condition and still
  22. // respond with a 2xx success to the provider — otherwise the provider will keep
  23. // retrying forever (e.g. when a foreign environment's webhook endpoint is
  24. // misconfigured to point at us, or when our orders table has been wiped).
  25. var ErrOrderNotFound = errors.New("payment order not found")
  26. const paymentFulfillmentLeaseDuration = 5 * time.Minute
  27. type paymentFulfillmentLease struct {
  28. version time.Time
  29. }
  30. // --- Payment Notification & Fulfillment ---
  31. func (s *PaymentService) HandlePaymentNotification(ctx context.Context, n *payment.PaymentNotification, pk string) error {
  32. if n.Status != payment.NotificationStatusSuccess {
  33. return nil
  34. }
  35. // Look up order by out_trade_no (the external order ID we sent to the provider)
  36. order, err := s.entClient.PaymentOrder.Query().Where(paymentorder.OutTradeNo(n.OrderID)).Only(ctx)
  37. if err != nil {
  38. // Fallback only for true legacy "sub2_N" DB-ID payloads when the
  39. // current out_trade_no lookup genuinely did not find an order.
  40. if oid, ok := parseLegacyPaymentOrderID(n.OrderID, err); ok {
  41. return s.confirmPayment(ctx, oid, n.TradeNo, n.Amount, pk, n.Metadata)
  42. }
  43. if dbent.IsNotFound(err) {
  44. return fmt.Errorf("%w: out_trade_no=%s", ErrOrderNotFound, n.OrderID)
  45. }
  46. return fmt.Errorf("lookup order failed for out_trade_no %s: %w", n.OrderID, err)
  47. }
  48. return s.confirmPayment(ctx, order.ID, n.TradeNo, n.Amount, pk, n.Metadata)
  49. }
  50. func parseLegacyPaymentOrderID(orderID string, lookupErr error) (int64, bool) {
  51. if !dbent.IsNotFound(lookupErr) {
  52. return 0, false
  53. }
  54. orderID = strings.TrimSpace(orderID)
  55. if !strings.HasPrefix(orderID, orderIDPrefix) {
  56. return 0, false
  57. }
  58. trimmed := strings.TrimPrefix(orderID, orderIDPrefix)
  59. if trimmed == "" || trimmed == orderID {
  60. return 0, false
  61. }
  62. oid, err := strconv.ParseInt(trimmed, 10, 64)
  63. if err != nil || oid <= 0 {
  64. return 0, false
  65. }
  66. return oid, true
  67. }
  68. func (s *PaymentService) confirmPayment(ctx context.Context, oid int64, tradeNo string, paid float64, pk string, metadata map[string]string) error {
  69. o, err := s.entClient.PaymentOrder.Get(ctx, oid)
  70. if err != nil {
  71. slog.Error("order not found", "orderID", oid)
  72. return nil
  73. }
  74. instanceProviderKey := ""
  75. if inst, instErr := s.getOrderProviderInstance(ctx, o); instErr == nil && inst != nil {
  76. instanceProviderKey = inst.ProviderKey
  77. }
  78. expectedProviderKey := expectedNotificationProviderKeyForOrder(s.registry, o, instanceProviderKey)
  79. if expectedProviderKey != "" && strings.TrimSpace(pk) != "" && !strings.EqualFold(expectedProviderKey, strings.TrimSpace(pk)) {
  80. s.writeAuditLog(ctx, o.ID, "PAYMENT_PROVIDER_MISMATCH", pk, map[string]any{
  81. "expectedProvider": expectedProviderKey,
  82. "actualProvider": pk,
  83. "tradeNo": tradeNo,
  84. })
  85. return fmt.Errorf("provider mismatch: expected %s, got %s", expectedProviderKey, pk)
  86. }
  87. if err := validateProviderNotificationMetadata(o, pk, metadata); err != nil {
  88. s.writeAuditLog(ctx, o.ID, "PAYMENT_PROVIDER_METADATA_MISMATCH", pk, map[string]any{
  89. "detail": err.Error(),
  90. "tradeNo": tradeNo,
  91. })
  92. return err
  93. }
  94. if !isValidProviderAmount(paid) {
  95. s.writeAuditLog(ctx, o.ID, "PAYMENT_INVALID_AMOUNT", pk, map[string]any{
  96. "expected": o.PayAmount,
  97. "paid": paid,
  98. "tradeNo": tradeNo,
  99. })
  100. return fmt.Errorf("invalid paid amount from provider: %v", paid)
  101. }
  102. if math.Abs(paid-o.PayAmount) > paymentAmountToleranceForCurrency(PaymentOrderCurrency(o)) {
  103. s.writeAuditLog(ctx, o.ID, "PAYMENT_AMOUNT_MISMATCH", pk, map[string]any{"expected": o.PayAmount, "paid": paid, "tradeNo": tradeNo})
  104. return fmt.Errorf("amount mismatch: expected %s, got %s", strconv.FormatFloat(o.PayAmount, 'f', -1, 64), strconv.FormatFloat(paid, 'f', -1, 64))
  105. }
  106. return s.toPaid(ctx, o, tradeNo, paid, pk)
  107. }
  108. func paymentAmountToleranceForCurrency(currency string) float64 {
  109. minorUnit := payment.CurrencyMinorUnit(currency)
  110. if minorUnit <= 2 {
  111. return amountToleranceCNY
  112. }
  113. return math.Pow10(-minorUnit) / 2
  114. }
  115. func isValidProviderAmount(amount float64) bool {
  116. return amount > 0 && !math.IsNaN(amount) && !math.IsInf(amount, 0)
  117. }
  118. func validateProviderNotificationMetadata(order *dbent.PaymentOrder, providerKey string, metadata map[string]string) error {
  119. return validateProviderSnapshotMetadata(order, providerKey, metadata)
  120. }
  121. func expectedNotificationProviderKey(registry *payment.Registry, orderPaymentType string, orderProviderKey string, instanceProviderKey string) string {
  122. if key := strings.TrimSpace(instanceProviderKey); key != "" {
  123. return key
  124. }
  125. if key := strings.TrimSpace(orderProviderKey); key != "" {
  126. return key
  127. }
  128. if registry != nil {
  129. if key := strings.TrimSpace(registry.GetProviderKey(payment.PaymentType(orderPaymentType))); key != "" {
  130. return key
  131. }
  132. }
  133. return strings.TrimSpace(orderPaymentType)
  134. }
  135. func (s *PaymentService) toPaid(ctx context.Context, o *dbent.PaymentOrder, tradeNo string, paid float64, pk string) error {
  136. previousStatus := o.Status
  137. now := time.Now()
  138. grace := now.Add(-paymentGraceMinutes * time.Minute)
  139. c, err := s.entClient.PaymentOrder.Update().Where(
  140. paymentorder.IDEQ(o.ID),
  141. paymentorder.Or(
  142. paymentorder.StatusEQ(OrderStatusPending),
  143. paymentorder.StatusEQ(OrderStatusCancelled),
  144. paymentorder.And(
  145. paymentorder.StatusEQ(OrderStatusExpired),
  146. paymentorder.UpdatedAtGTE(grace),
  147. ),
  148. ),
  149. ).SetStatus(OrderStatusPaid).SetPayAmount(paid).SetPaymentTradeNo(tradeNo).SetPaidAt(now).ClearFailedAt().ClearFailedReason().Save(ctx)
  150. if err != nil {
  151. return fmt.Errorf("update to PAID: %w", err)
  152. }
  153. if c == 0 {
  154. return s.alreadyProcessed(ctx, o)
  155. }
  156. if previousStatus == OrderStatusCancelled || previousStatus == OrderStatusExpired {
  157. slog.Info("order recovered from webhook payment success",
  158. "orderID", o.ID,
  159. "previousStatus", previousStatus,
  160. "tradeNo", tradeNo,
  161. "provider", pk,
  162. )
  163. s.writeAuditLog(ctx, o.ID, "ORDER_RECOVERED", pk, map[string]any{
  164. "previous_status": previousStatus,
  165. "tradeNo": tradeNo,
  166. "paidAmount": paid,
  167. "reason": "webhook payment success received after order " + previousStatus,
  168. })
  169. }
  170. s.writeAuditLog(ctx, o.ID, "ORDER_PAID", pk, map[string]any{"tradeNo": tradeNo, "paidAmount": paid})
  171. return s.executeFulfillment(ctx, o.ID)
  172. }
  173. func (s *PaymentService) alreadyProcessed(ctx context.Context, o *dbent.PaymentOrder) error {
  174. cur, err := s.entClient.PaymentOrder.Get(ctx, o.ID)
  175. if err != nil {
  176. return nil
  177. }
  178. switch cur.Status {
  179. case OrderStatusCompleted, OrderStatusRefunded:
  180. return nil
  181. case OrderStatusFailed, OrderStatusPaid, OrderStatusRecharging:
  182. return s.executeFulfillment(ctx, o.ID)
  183. case OrderStatusExpired:
  184. slog.Warn("webhook payment success for expired order beyond grace period",
  185. "orderID", o.ID,
  186. "status", cur.Status,
  187. "updatedAt", cur.UpdatedAt,
  188. )
  189. s.writeAuditLog(ctx, o.ID, "PAYMENT_AFTER_EXPIRY", "system", map[string]any{
  190. "status": cur.Status,
  191. "updatedAt": cur.UpdatedAt,
  192. "reason": "payment arrived after expiry grace period",
  193. })
  194. return nil
  195. default:
  196. return nil
  197. }
  198. }
  199. func (s *PaymentService) executeFulfillment(ctx context.Context, oid int64) error {
  200. o, err := s.entClient.PaymentOrder.Get(ctx, oid)
  201. if err != nil {
  202. return fmt.Errorf("get order: %w", err)
  203. }
  204. if o.OrderType == payment.OrderTypeSubscription {
  205. return s.ExecuteSubscriptionFulfillment(ctx, oid)
  206. }
  207. return s.ExecuteBalanceFulfillment(ctx, oid)
  208. }
  209. func (s *PaymentService) ExecuteBalanceFulfillment(ctx context.Context, oid int64) error {
  210. o, err := s.entClient.PaymentOrder.Get(ctx, oid)
  211. if err != nil {
  212. return infraerrors.NotFound("NOT_FOUND", "order not found")
  213. }
  214. if o.Status == OrderStatusCompleted {
  215. return nil
  216. }
  217. if psIsRefundStatus(o.Status) {
  218. return infraerrors.BadRequest("INVALID_STATUS", "refund-related order cannot fulfill")
  219. }
  220. if o.Status != OrderStatusPaid && o.Status != OrderStatusFailed && o.Status != OrderStatusRecharging {
  221. return infraerrors.BadRequest("INVALID_STATUS", "order cannot fulfill in status "+o.Status)
  222. }
  223. lease, err := s.acquirePaymentFulfillmentLease(ctx, o)
  224. if err != nil {
  225. return err
  226. }
  227. if lease == nil {
  228. return nil
  229. }
  230. if err := s.doBalance(ctx, o, lease); err != nil {
  231. s.markFailed(ctx, oid, lease, err)
  232. return err
  233. }
  234. return nil
  235. }
  236. func (s *PaymentService) acquirePaymentFulfillmentLease(ctx context.Context, o *dbent.PaymentOrder) (*paymentFulfillmentLease, error) {
  237. if o == nil {
  238. return nil, infraerrors.BadRequest("INVALID_STATUS", "nil payment order")
  239. }
  240. now := time.Now().UTC().Truncate(time.Microsecond)
  241. staleBefore := now.Add(-paymentFulfillmentLeaseDuration)
  242. updated, err := s.entClient.PaymentOrder.Update().
  243. Where(
  244. paymentorder.IDEQ(o.ID),
  245. paymentorder.Or(
  246. paymentorder.StatusIn(OrderStatusPaid, OrderStatusFailed),
  247. paymentorder.And(
  248. paymentorder.StatusEQ(OrderStatusRecharging),
  249. paymentorder.UpdatedAtLTE(staleBefore),
  250. ),
  251. ),
  252. ).
  253. SetStatus(OrderStatusRecharging).
  254. SetUpdatedAt(now).
  255. ClearFailedAt().
  256. ClearFailedReason().
  257. Save(ctx)
  258. if err != nil {
  259. return nil, fmt.Errorf("acquire fulfillment lease: %w", err)
  260. }
  261. if updated == 0 {
  262. current, getErr := s.entClient.PaymentOrder.Get(ctx, o.ID)
  263. if getErr != nil {
  264. return nil, fmt.Errorf("reload fulfillment lease: %w", getErr)
  265. }
  266. if current.Status == OrderStatusCompleted {
  267. return nil, nil
  268. }
  269. if current.Status == OrderStatusRecharging {
  270. return nil, infraerrors.Conflict("CONFLICT", "order is being processed")
  271. }
  272. return nil, infraerrors.Conflict("CONFLICT", "order status changed while acquiring fulfillment lease")
  273. }
  274. // Reload the persisted timestamp instead of trusting application clock precision.
  275. claimed, err := s.entClient.PaymentOrder.Get(ctx, o.ID)
  276. if err != nil {
  277. return nil, fmt.Errorf("reload acquired fulfillment lease: %w", err)
  278. }
  279. if claimed.Status != OrderStatusRecharging {
  280. return nil, infraerrors.Conflict("CONFLICT", "fulfillment lease was lost")
  281. }
  282. return &paymentFulfillmentLease{version: claimed.UpdatedAt}, nil
  283. }
  284. // redeemAction represents the idempotency decision for balance fulfillment.
  285. type redeemAction int
  286. const (
  287. // redeemActionCreate: code does not exist — create it, then redeem.
  288. redeemActionCreate redeemAction = iota
  289. // redeemActionRedeem: code exists but is unused — skip creation, redeem only.
  290. redeemActionRedeem
  291. // redeemActionSkipCompleted: code exists and is already used — skip to mark completed.
  292. redeemActionSkipCompleted
  293. )
  294. // resolveRedeemAction decides the idempotency action based on an existing redeem code lookup.
  295. // existing is the result of GetByCode; lookupErr is the error from that call.
  296. func resolveRedeemAction(existing *RedeemCode, lookupErr error) (redeemAction, error) {
  297. if lookupErr != nil {
  298. if errors.Is(lookupErr, ErrRedeemCodeNotFound) {
  299. return redeemActionCreate, nil
  300. }
  301. return redeemActionCreate, fmt.Errorf("lookup payment redeem code: %w", lookupErr)
  302. }
  303. if existing == nil {
  304. return redeemActionCreate, nil
  305. }
  306. if existing.IsUsed() {
  307. return redeemActionSkipCompleted, nil
  308. }
  309. return redeemActionRedeem, nil
  310. }
  311. func validatePaymentRedeemCode(o *dbent.PaymentOrder, code *RedeemCode) error {
  312. if o == nil || code == nil {
  313. return errors.New("payment redeem code validation requires an order and code")
  314. }
  315. if code.Code != o.RechargeCode {
  316. return fmt.Errorf("payment redeem code mismatch for order %d", o.ID)
  317. }
  318. if code.Type != RedeemTypeBalance {
  319. return fmt.Errorf("payment redeem code type mismatch for order %d: got %s", o.ID, code.Type)
  320. }
  321. if math.IsNaN(code.Value) || math.IsInf(code.Value, 0) || math.Abs(code.Value-o.Amount) > 1e-8 {
  322. return fmt.Errorf("payment redeem code amount mismatch for order %d: expected %.8f, got %.8f", o.ID, o.Amount, code.Value)
  323. }
  324. switch code.Status {
  325. case StatusUnused:
  326. if code.UsedBy != nil {
  327. return fmt.Errorf("unused payment redeem code has a user for order %d", o.ID)
  328. }
  329. case StatusUsed:
  330. if code.UsedBy == nil || *code.UsedBy != o.UserID {
  331. return fmt.Errorf("payment redeem code user mismatch for order %d", o.ID)
  332. }
  333. default:
  334. return fmt.Errorf("payment redeem code has invalid status for order %d: %s", o.ID, code.Status)
  335. }
  336. return nil
  337. }
  338. func (s *PaymentService) doBalance(ctx context.Context, o *dbent.PaymentOrder, lease *paymentFulfillmentLease) error {
  339. // Idempotency: check if redeem code already exists (from a previous partial run)
  340. existing, lookupErr := s.redeemService.GetByCode(ctx, o.RechargeCode)
  341. action, err := resolveRedeemAction(existing, lookupErr)
  342. if err != nil {
  343. return err
  344. }
  345. if existing != nil {
  346. if err := validatePaymentRedeemCode(o, existing); err != nil {
  347. return err
  348. }
  349. }
  350. switch action {
  351. case redeemActionSkipCompleted:
  352. if err := s.applyAffiliateRebateForOrder(ctx, o); err != nil {
  353. return err
  354. }
  355. // Code already created and redeemed — just mark completed
  356. return s.markCompleted(ctx, o, lease, "RECHARGE_SUCCESS")
  357. case redeemActionCreate:
  358. rc := &RedeemCode{Code: o.RechargeCode, Type: RedeemTypeBalance, Value: o.Amount, Status: StatusUnused}
  359. if err := s.redeemService.CreateCode(ctx, rc); err != nil {
  360. return fmt.Errorf("create redeem code: %w", err)
  361. }
  362. case redeemActionRedeem:
  363. // Code exists but unused — skip creation, proceed to redeem
  364. }
  365. if _, err := s.redeemService.redeemForPaymentFulfillment(ctx, o.UserID, o.RechargeCode); err != nil {
  366. return fmt.Errorf("redeem balance: %w", err)
  367. }
  368. if err := s.applyAffiliateRebateForOrder(ctx, o); err != nil {
  369. return err
  370. }
  371. return s.markCompleted(ctx, o, lease, "RECHARGE_SUCCESS")
  372. }
  373. func (s *PaymentService) markCompleted(ctx context.Context, o *dbent.PaymentOrder, lease *paymentFulfillmentLease, auditAction string) error {
  374. if lease == nil {
  375. return errors.New("missing payment fulfillment lease")
  376. }
  377. now := time.Now()
  378. updated, err := s.entClient.PaymentOrder.Update().Where(
  379. paymentorder.IDEQ(o.ID),
  380. paymentorder.StatusEQ(OrderStatusRecharging),
  381. paymentorder.UpdatedAtEQ(lease.version),
  382. ).SetStatus(OrderStatusCompleted).SetCompletedAt(now).Save(ctx)
  383. if err != nil {
  384. return fmt.Errorf("mark completed: %w", err)
  385. }
  386. if updated == 0 {
  387. current, getErr := s.entClient.PaymentOrder.Get(ctx, o.ID)
  388. if getErr == nil && current.Status == OrderStatusCompleted {
  389. return nil
  390. }
  391. return infraerrors.Conflict("CONFLICT", "fulfillment lease was lost before completion")
  392. }
  393. if !s.hasAuditLog(ctx, o.ID, auditAction) {
  394. s.writeAuditLog(ctx, o.ID, auditAction, "system", map[string]any{
  395. "rechargeCode": o.RechargeCode,
  396. "creditedAmount": o.Amount,
  397. "payAmount": o.PayAmount,
  398. })
  399. s.dispatchPaymentFulfillmentNotification(o, auditAction)
  400. }
  401. return nil
  402. }
  403. func (s *PaymentService) dispatchPaymentFulfillmentNotification(o *dbent.PaymentOrder, auditAction string) {
  404. if s == nil || s.notificationEmailService == nil || o == nil {
  405. return
  406. }
  407. go func() {
  408. ctx, cancel := context.WithTimeout(context.Background(), emailSendTimeout)
  409. defer cancel()
  410. var err error
  411. switch auditAction {
  412. case "RECHARGE_SUCCESS":
  413. err = s.sendBalanceRechargeSuccessNotification(ctx, o)
  414. case "SUBSCRIPTION_SUCCESS":
  415. err = s.sendSubscriptionPurchaseSuccessNotification(ctx, o)
  416. default:
  417. return
  418. }
  419. if err != nil {
  420. slog.Warn("payment fulfillment notification email failed", "order_id", o.ID, "action", auditAction, "err", err.Error())
  421. }
  422. }()
  423. }
  424. func (s *PaymentService) sendBalanceRechargeSuccessNotification(ctx context.Context, o *dbent.PaymentOrder) error {
  425. currentBalance := ""
  426. if s.userRepo != nil {
  427. if user, err := s.userRepo.GetByID(ctx, o.UserID); err == nil && user != nil {
  428. currentBalance = fmt.Sprintf("%.2f", user.Balance)
  429. }
  430. }
  431. return s.notificationEmailService.Send(ctx, NotificationEmailSendInput{
  432. Event: NotificationEmailEventBalanceRechargeSuccess,
  433. RecipientEmail: o.UserEmail,
  434. RecipientName: firstNonEmpty(o.UserName, o.UserEmail),
  435. UserID: o.UserID,
  436. SourceType: "payment_order",
  437. SourceID: strconv.FormatInt(o.ID, 10),
  438. Variables: map[string]string{
  439. "recharge_amount": fmt.Sprintf("%.2f", o.Amount),
  440. "current_balance": currentBalance,
  441. "order_id": strconv.FormatInt(o.ID, 10),
  442. },
  443. })
  444. }
  445. func (s *PaymentService) sendSubscriptionPurchaseSuccessNotification(ctx context.Context, o *dbent.PaymentOrder) error {
  446. variables := map[string]string{
  447. "subscription_group": "Subscription",
  448. "subscription_days": "",
  449. "expiry_time": "",
  450. "order_id": strconv.FormatInt(o.ID, 10),
  451. }
  452. if o.SubscriptionDays != nil {
  453. variables["subscription_days"] = strconv.Itoa(*o.SubscriptionDays)
  454. }
  455. if o.SubscriptionGroupID != nil {
  456. if s.groupRepo != nil {
  457. if group, err := s.groupRepo.GetByID(ctx, *o.SubscriptionGroupID); err == nil && group != nil && strings.TrimSpace(group.Name) != "" {
  458. variables["subscription_group"] = group.Name
  459. }
  460. }
  461. if s.subscriptionSvc != nil {
  462. if sub, err := s.subscriptionSvc.GetActiveSubscription(ctx, o.UserID, *o.SubscriptionGroupID); err == nil && sub != nil {
  463. variables["expiry_time"] = sub.ExpiresAt.Format("2006-01-02 15:04")
  464. }
  465. }
  466. }
  467. return s.notificationEmailService.Send(ctx, NotificationEmailSendInput{
  468. Event: NotificationEmailEventSubscriptionPurchaseSuccess,
  469. RecipientEmail: o.UserEmail,
  470. RecipientName: firstNonEmpty(o.UserName, o.UserEmail),
  471. UserID: o.UserID,
  472. SourceType: "payment_order",
  473. SourceID: strconv.FormatInt(o.ID, 10),
  474. Variables: variables,
  475. })
  476. }
  477. func (s *PaymentService) ExecuteSubscriptionFulfillment(ctx context.Context, oid int64) error {
  478. o, err := s.entClient.PaymentOrder.Get(ctx, oid)
  479. if err != nil {
  480. return infraerrors.NotFound("NOT_FOUND", "order not found")
  481. }
  482. if o.Status == OrderStatusCompleted {
  483. return nil
  484. }
  485. if psIsRefundStatus(o.Status) {
  486. return infraerrors.BadRequest("INVALID_STATUS", "refund-related order cannot fulfill")
  487. }
  488. if o.Status != OrderStatusPaid && o.Status != OrderStatusFailed && o.Status != OrderStatusRecharging {
  489. return infraerrors.BadRequest("INVALID_STATUS", "order cannot fulfill in status "+o.Status)
  490. }
  491. if o.SubscriptionGroupID == nil || o.SubscriptionDays == nil {
  492. return infraerrors.BadRequest("INVALID_STATUS", "missing subscription info")
  493. }
  494. lease, err := s.acquirePaymentFulfillmentLease(ctx, o)
  495. if err != nil {
  496. return err
  497. }
  498. if lease == nil {
  499. return nil
  500. }
  501. if err := s.doSub(ctx, o, lease); err != nil {
  502. s.markFailed(ctx, oid, lease, err)
  503. return err
  504. }
  505. return nil
  506. }
  507. func (s *PaymentService) doSub(ctx context.Context, o *dbent.PaymentOrder, lease *paymentFulfillmentLease) error {
  508. gid := *o.SubscriptionGroupID
  509. days := *o.SubscriptionDays
  510. g, err := s.groupRepo.GetByID(ctx, gid)
  511. if err != nil || g.Status != payment.EntityStatusActive {
  512. return fmt.Errorf("group %d no longer exists or inactive", gid)
  513. }
  514. if err := s.ensurePaymentSubscriptionAssigned(ctx, o, gid, days); err != nil {
  515. return err
  516. }
  517. if err := s.applyAffiliateRebateForOrder(ctx, o); err != nil {
  518. return err
  519. }
  520. return s.markCompleted(ctx, o, lease, "SUBSCRIPTION_SUCCESS")
  521. }
  522. func (s *PaymentService) ensurePaymentSubscriptionAssigned(ctx context.Context, o *dbent.PaymentOrder, groupID int64, days int) error {
  523. if s.subscriptionSvc == nil {
  524. return errors.New("subscription service is unavailable")
  525. }
  526. tx, err := s.entClient.Tx(ctx)
  527. if err != nil {
  528. return fmt.Errorf("begin subscription fulfillment tx: %w", err)
  529. }
  530. defer func() { _ = tx.Rollback() }()
  531. txCtx := dbent.NewTxContext(ctx, tx)
  532. txClient := tx.Client()
  533. alreadyAssigned, err := hasPaymentSubscriptionAssignmentAudit(txCtx, txClient, o.ID)
  534. if err != nil {
  535. return fmt.Errorf("check subscription assignment audit: %w", err)
  536. }
  537. recoveredFromNote := false
  538. if !alreadyAssigned {
  539. orderNote := paymentSubscriptionOrderNote(o.ID)
  540. existing, lookupErr := s.subscriptionSvc.userSubRepo.GetByUserIDAndGroupID(txCtx, o.UserID, groupID)
  541. switch {
  542. case lookupErr == nil && existing != nil && hasPaymentSubscriptionOrderNote(existing.Notes, orderNote):
  543. recoveredFromNote = true
  544. case lookupErr != nil && !errors.Is(lookupErr, ErrSubscriptionNotFound):
  545. return fmt.Errorf("check existing subscription assignment: %w", lookupErr)
  546. default:
  547. if _, _, err := s.subscriptionSvc.assignOrExtendSubscription(txCtx, &AssignSubscriptionInput{
  548. UserID: o.UserID,
  549. GroupID: groupID,
  550. ValidityDays: days,
  551. AssignedBy: 0,
  552. Notes: orderNote,
  553. }, true); err != nil {
  554. return fmt.Errorf("assign subscription: %w", err)
  555. }
  556. }
  557. detail, _ := json.Marshal(map[string]any{
  558. "groupID": groupID,
  559. "validityDays": days,
  560. "recoveredFromNote": recoveredFromNote,
  561. })
  562. if _, err := txClient.PaymentAuditLog.Create().
  563. SetOrderID(strconv.FormatInt(o.ID, 10)).
  564. SetAction("SUBSCRIPTION_ASSIGNED").
  565. SetDetail(string(detail)).
  566. SetOperator("system").
  567. Save(txCtx); err != nil {
  568. if dbent.IsConstraintError(err) {
  569. _ = tx.Rollback()
  570. claimed, checkErr := hasPaymentSubscriptionAssignmentAudit(ctx, s.entClient, o.ID)
  571. if checkErr == nil && claimed {
  572. return s.subscriptionSvc.invalidateSubscriptionCaches(o.UserID, groupID)
  573. }
  574. }
  575. return fmt.Errorf("record subscription assignment audit: %w", err)
  576. }
  577. } else {
  578. slog.Info("subscription already assigned for order, skipping", "orderID", o.ID, "groupID", groupID)
  579. }
  580. if err := tx.Commit(); err != nil {
  581. return fmt.Errorf("commit subscription fulfillment tx: %w", err)
  582. }
  583. // Assignment cache invalidation is deferred while this transaction is open,
  584. // then performed synchronously against the committed subscription.
  585. if err := s.subscriptionSvc.invalidateSubscriptionCaches(o.UserID, groupID); err != nil {
  586. return fmt.Errorf("invalidate subscription cache after fulfillment: %w", err)
  587. }
  588. return nil
  589. }
  590. func hasPaymentSubscriptionAssignmentAudit(ctx context.Context, client *dbent.Client, orderID int64) (bool, error) {
  591. count, err := client.PaymentAuditLog.Query().
  592. Where(
  593. paymentauditlog.OrderIDEQ(strconv.FormatInt(orderID, 10)),
  594. paymentauditlog.ActionIn("SUBSCRIPTION_ASSIGNED", "SUBSCRIPTION_SUCCESS"),
  595. ).
  596. Limit(1).
  597. Count(ctx)
  598. return count > 0, err
  599. }
  600. func paymentSubscriptionOrderNote(orderID int64) string {
  601. return fmt.Sprintf("payment order %d", orderID)
  602. }
  603. func hasPaymentSubscriptionOrderNote(notes string, orderNote string) bool {
  604. for _, line := range strings.Split(strings.ReplaceAll(notes, "\r\n", "\n"), "\n") {
  605. if strings.TrimSpace(line) == orderNote {
  606. return true
  607. }
  608. }
  609. return false
  610. }
  611. func (s *PaymentService) hasAuditLog(ctx context.Context, orderID int64, action string) bool {
  612. oid := strconv.FormatInt(orderID, 10)
  613. c, _ := s.entClient.PaymentAuditLog.Query().
  614. Where(paymentauditlog.OrderIDEQ(oid), paymentauditlog.ActionEQ(action)).
  615. Limit(1).Count(ctx)
  616. return c > 0
  617. }
  618. func (s *PaymentService) applyAffiliateRebateForOrder(ctx context.Context, o *dbent.PaymentOrder) error {
  619. baseAmount := affiliateRebateBaseAmount(o)
  620. if o == nil || baseAmount <= 0 {
  621. return nil
  622. }
  623. if s.affiliateService == nil {
  624. return nil
  625. }
  626. tx, err := s.entClient.Tx(ctx)
  627. if err != nil {
  628. s.writeAuditLog(ctx, o.ID, "AFFILIATE_REBATE_FAILED", "system", map[string]any{
  629. "error": fmt.Sprintf("begin affiliate rebate tx: %v", err),
  630. })
  631. return fmt.Errorf("begin affiliate rebate tx: %w", err)
  632. }
  633. defer func() { _ = tx.Rollback() }()
  634. txCtx := dbent.NewTxContext(ctx, tx)
  635. claimed, err := s.tryClaimAffiliateRebateAudit(txCtx, tx.Client(), o.ID, baseAmount)
  636. if err != nil {
  637. s.writeAuditLog(ctx, o.ID, "AFFILIATE_REBATE_FAILED", "system", map[string]any{
  638. "error": err.Error(),
  639. })
  640. return fmt.Errorf("claim affiliate rebate audit: %w", err)
  641. }
  642. if !claimed {
  643. return nil
  644. }
  645. sourceOrderID := o.ID
  646. rebateAmount, err := s.affiliateService.AccrueInviteRebateForOrder(txCtx, o.UserID, baseAmount, &sourceOrderID)
  647. if err != nil {
  648. s.writeAuditLog(ctx, o.ID, "AFFILIATE_REBATE_FAILED", "system", map[string]any{
  649. "error": err.Error(),
  650. })
  651. return fmt.Errorf("accrue affiliate rebate: %w", err)
  652. }
  653. if rebateAmount <= 0 {
  654. if err := s.updateClaimedAffiliateRebateAudit(txCtx, tx.Client(), o.ID, "AFFILIATE_REBATE_SKIPPED", map[string]any{
  655. "baseAmount": baseAmount,
  656. "reason": "no inviter bound or rebate amount <= 0",
  657. }); err != nil {
  658. s.writeAuditLog(ctx, o.ID, "AFFILIATE_REBATE_FAILED", "system", map[string]any{
  659. "error": err.Error(),
  660. })
  661. return fmt.Errorf("update affiliate rebate skipped audit: %w", err)
  662. }
  663. if err := tx.Commit(); err != nil {
  664. s.writeAuditLog(ctx, o.ID, "AFFILIATE_REBATE_FAILED", "system", map[string]any{
  665. "error": fmt.Sprintf("commit affiliate rebate tx: %v", err),
  666. })
  667. return fmt.Errorf("commit affiliate rebate tx: %w", err)
  668. }
  669. return nil
  670. }
  671. if err := s.updateClaimedAffiliateRebateAudit(txCtx, tx.Client(), o.ID, "AFFILIATE_REBATE_APPLIED", map[string]any{
  672. "baseAmount": baseAmount,
  673. "rebateAmount": rebateAmount,
  674. }); err != nil {
  675. s.writeAuditLog(ctx, o.ID, "AFFILIATE_REBATE_FAILED", "system", map[string]any{
  676. "error": err.Error(),
  677. })
  678. return fmt.Errorf("update affiliate rebate applied audit: %w", err)
  679. }
  680. if err := tx.Commit(); err != nil {
  681. s.writeAuditLog(ctx, o.ID, "AFFILIATE_REBATE_FAILED", "system", map[string]any{
  682. "error": fmt.Sprintf("commit affiliate rebate tx: %v", err),
  683. })
  684. return fmt.Errorf("commit affiliate rebate tx: %w", err)
  685. }
  686. return nil
  687. }
  688. func affiliateRebateBaseAmount(o *dbent.PaymentOrder) float64 {
  689. if o == nil {
  690. return 0
  691. }
  692. switch o.OrderType {
  693. case payment.OrderTypeBalance, payment.OrderTypeSubscription:
  694. return o.Amount
  695. default:
  696. return 0
  697. }
  698. }
  699. func (s *PaymentService) tryClaimAffiliateRebateAudit(ctx context.Context, client *dbent.Client, orderID int64, baseAmount float64) (bool, error) {
  700. if client == nil {
  701. return false, errors.New("nil payment client")
  702. }
  703. oid := strconv.FormatInt(orderID, 10)
  704. detail, _ := json.Marshal(map[string]any{
  705. "baseAmount": baseAmount,
  706. "status": "reserved",
  707. })
  708. query, args := buildAffiliateRebateAuditClaimQuery(client, oid, string(detail))
  709. rows, err := client.QueryContext(ctx, query, args...)
  710. if err != nil {
  711. return false, err
  712. }
  713. defer func() { _ = rows.Close() }()
  714. if !rows.Next() {
  715. if err := rows.Err(); err != nil {
  716. return false, err
  717. }
  718. return false, nil
  719. }
  720. var claimID int64
  721. if err := rows.Scan(&claimID); err != nil {
  722. return false, err
  723. }
  724. return true, nil
  725. }
  726. func buildAffiliateRebateAuditClaimQuery(client *dbent.Client, orderID, detail string) (string, []any) {
  727. nowExpr := paymentAuditCurrentTimestampExpr(client)
  728. if paymentAuditDialect(client) == dialect.Postgres {
  729. return fmt.Sprintf(`
  730. INSERT INTO payment_audit_logs (order_id, action, detail, operator, created_at)
  731. SELECT $1::text, 'AFFILIATE_REBATE_APPLIED', $2::text, 'system', %s
  732. WHERE NOT EXISTS (
  733. SELECT 1
  734. FROM payment_audit_logs
  735. WHERE order_id = $1::text
  736. AND action IN ('AFFILIATE_REBATE_APPLIED', 'AFFILIATE_REBATE_SKIPPED')
  737. )
  738. ON CONFLICT (order_id, action) DO NOTHING
  739. RETURNING id`, nowExpr), []any{orderID, detail}
  740. }
  741. return fmt.Sprintf(`
  742. INSERT INTO payment_audit_logs (order_id, action, detail, operator, created_at)
  743. SELECT ?, 'AFFILIATE_REBATE_APPLIED', ?, 'system', %s
  744. WHERE NOT EXISTS (
  745. SELECT 1
  746. FROM payment_audit_logs
  747. WHERE order_id = ?
  748. AND action IN ('AFFILIATE_REBATE_APPLIED', 'AFFILIATE_REBATE_SKIPPED')
  749. )
  750. ON CONFLICT (order_id, action) DO NOTHING
  751. RETURNING id`, nowExpr), []any{orderID, detail, orderID}
  752. }
  753. func paymentAuditCurrentTimestampExpr(client *dbent.Client) string {
  754. if paymentAuditDialect(client) == dialect.Postgres {
  755. return "NOW()"
  756. }
  757. return "CURRENT_TIMESTAMP"
  758. }
  759. func paymentAuditDialect(client *dbent.Client) string {
  760. if client == nil || client.Driver() == nil {
  761. return ""
  762. }
  763. return client.Driver().Dialect()
  764. }
  765. func (s *PaymentService) updateClaimedAffiliateRebateAudit(ctx context.Context, client *dbent.Client, orderID int64, action string, detail map[string]any) error {
  766. if client == nil {
  767. return errors.New("nil payment client")
  768. }
  769. oid := strconv.FormatInt(orderID, 10)
  770. detailJSON, _ := json.Marshal(detail)
  771. updated, err := client.PaymentAuditLog.Update().
  772. Where(
  773. paymentauditlog.OrderIDEQ(oid),
  774. paymentauditlog.ActionEQ("AFFILIATE_REBATE_APPLIED"),
  775. ).
  776. SetAction(action).
  777. SetDetail(string(detailJSON)).
  778. SetOperator("system").
  779. Save(ctx)
  780. if err != nil {
  781. return err
  782. }
  783. if updated == 0 {
  784. return errors.New("affiliate rebate claim log not found")
  785. }
  786. return nil
  787. }
  788. func (s *PaymentService) markFailed(ctx context.Context, oid int64, lease *paymentFulfillmentLease, cause error) {
  789. if lease == nil {
  790. slog.Error("mark FAILED without fulfillment lease", "orderID", oid)
  791. return
  792. }
  793. now := time.Now()
  794. r := psErrMsg(cause)
  795. // The lease version prevents a stale worker from overwriting a newer owner.
  796. c, e := s.entClient.PaymentOrder.Update().
  797. Where(
  798. paymentorder.IDEQ(oid),
  799. paymentorder.StatusEQ(OrderStatusRecharging),
  800. paymentorder.UpdatedAtEQ(lease.version),
  801. ).
  802. SetStatus(OrderStatusFailed).SetFailedAt(now).SetFailedReason(r).Save(ctx)
  803. if e != nil {
  804. slog.Error("mark FAILED", "orderID", oid, "error", e)
  805. }
  806. if c > 0 {
  807. s.writeAuditLog(ctx, oid, "FULFILLMENT_FAILED", "system", map[string]any{"reason": r})
  808. }
  809. }
  810. func (s *PaymentService) RetryFulfillment(ctx context.Context, oid int64) error {
  811. o, err := s.entClient.PaymentOrder.Get(ctx, oid)
  812. if err != nil {
  813. return infraerrors.NotFound("NOT_FOUND", "order not found")
  814. }
  815. if o.PaidAt == nil {
  816. return infraerrors.BadRequest("INVALID_STATUS", "order is not paid")
  817. }
  818. if psIsRefundStatus(o.Status) {
  819. return infraerrors.BadRequest("INVALID_STATUS", "refund-related order cannot retry")
  820. }
  821. if o.Status == OrderStatusCompleted {
  822. return infraerrors.BadRequest("INVALID_STATUS", "order already completed")
  823. }
  824. if o.Status != OrderStatusFailed && o.Status != OrderStatusPaid && o.Status != OrderStatusRecharging {
  825. return infraerrors.BadRequest("INVALID_STATUS", "only paid, failed, and recoverable recharging orders can retry")
  826. }
  827. s.writeAuditLog(ctx, oid, "RECHARGE_RETRY", "admin", map[string]any{"detail": "admin manual retry"})
  828. return s.executeFulfillment(ctx, oid)
  829. }