Merge pull request 'ledger autoresolution' (#327) from ledger-326 into main

Reviewed-on: #327

api/billing/fees/internal/service/fees/internal/resolver/impl.go

@@ -8,6 +8,7 @@ import (
 	"github.com/tech/sendico/billing/fees/storage"
 	"github.com/tech/sendico/billing/fees/storage/model"
 	"github.com/tech/sendico/pkg/merrors"
+	"github.com/tech/sendico/pkg/mutil/mzap"
 	"go.mongodb.org/mongo-driver/bson/primitive"
 	"go.uber.org/zap"
 )
@@ -49,12 +50,19 @@ func (r *feeResolver) ResolveFeeRule(ctx context.Context, orgRef *primitive.Obje
 			if rule, selErr := selectRule(plan, trigger, at, attrs); selErr == nil {
 				return plan, rule, nil
 			} else if !errors.Is(selErr, ErrNoFeeRuleFound) {
-				r.logger.Warn("failed selecting rule for org plan", zap.Error(selErr), zap.String("org_ref", orgRef.Hex()))
+				r.logger.Warn("Failed selecting rule for org plan", zap.Error(selErr), zap.String("org_ref", orgRef.Hex()))
 				return nil, nil, selErr
 			}
-			r.logger.Debug("no matching rule in org plan; falling back to global", zap.String("org_ref", orgRef.Hex()))
+			r.logger.Debug(
+				"No matching rule in org plan; falling back to global",
+				mzap.ObjRef("org_ref", *orgRef),
+				zap.String("trigger", string(trigger)),
+				zap.Time("booked_at", at),
+				zap.Any("attributes", attrs),
+				zapFieldsForPlan(plan)...,
+			)
 		} else if !errors.Is(err, storage.ErrFeePlanNotFound) {
-			r.logger.Warn("failed resolving org fee plan", zap.Error(err), zap.String("org_ref", orgRef.Hex()))
+			r.logger.Warn("Failed resolving org fee plan", zap.Error(err), zap.String("org_ref", orgRef.Hex()))
 			return nil, nil, err
 		}
 	}
@@ -62,16 +70,23 @@ func (r *feeResolver) ResolveFeeRule(ctx context.Context, orgRef *primitive.Obje
 	plan, err := r.getGlobalPlan(ctx, at)
 	if err != nil {
 		if errors.Is(err, storage.ErrFeePlanNotFound) {
+			r.logger.Debug("No applicable global fee plan found", zap.String("trigger", string(trigger)),
+				zap.Time("booked_at", at), zap.Any("attributes", attrs),
+			)
 			return nil, nil, merrors.NoData("fees: no applicable fee rule found")
 		}
-		r.logger.Warn("failed resolving global fee plan", zap.Error(err))
+		r.logger.Warn("Failed resolving global fee plan", zap.Error(err))
 		return nil, nil, err
 	}
 
 	rule, err := selectRule(plan, trigger, at, attrs)
 	if err != nil {
 		if !errors.Is(err, ErrNoFeeRuleFound) {
-			r.logger.Warn("failed selecting rule in global plan", zap.Error(err))
+			r.logger.Warn("Failed selecting rule in global plan", zap.Error(err))
+		} else {
+			r.logger.Debug("No matching rule in global plan", zap.String("trigger", string(trigger)),
+				zap.Time("booked_at", at), zap.Any("attributes", attrs), zapFieldsForPlan(plan)...,
+			)
 		}
 		return nil, nil, err
 	}
@@ -146,3 +161,29 @@ func matchesAppliesTo(appliesTo map[string]string, attrs map[string]string) bool
 	}
 	return true
 }
+
+func zapFieldsForPlan(plan *model.FeePlan) []zap.Field {
+	if plan == nil {
+		return []zap.Field{zap.Bool("plan_present", false)}
+	}
+	fields := []zap.Field{
+		zap.Bool("plan_present", true),
+		zap.Bool("plan_active", plan.Active),
+		zap.Time("plan_effective_from", plan.EffectiveFrom),
+		zap.Int("plan_rules_count", len(plan.Rules)),
+	}
+	if plan.EffectiveTo != nil {
+		fields = append(fields, zap.Time("plan_effective_to", *plan.EffectiveTo))
+	} else {
+		fields = append(fields, zap.Bool("plan_effective_to_set", false))
+	}
+	if plan.OrganizationRef != nil && !plan.OrganizationRef.IsZero() {
+		fields = append(fields, zap.String("plan_org_ref", plan.OrganizationRef.Hex()))
+	} else {
+		fields = append(fields, zap.Bool("plan_org_ref_set", false))
+	}
+	if plan.GetID() != nil && !plan.GetID().IsZero() {
+		fields = append(fields, zap.String("plan_id", plan.GetID().Hex()))
+	}
+	return fields
+}

api/billing/fees/internal/service/fees/service.go

@@ -5,6 +5,7 @@ import (
 	"encoding/base64"
 	"encoding/json"
 	"errors"
+	"fmt"
 	"strings"
 	"time"
 
@@ -434,18 +435,18 @@ func (s *Service) computeQuoteWithTime(ctx context.Context, orgRef primitive.Obj
 
 	plan, rule, err := s.resolver.ResolveFeeRule(ctx, orgPtr, convertTrigger(intent.GetTrigger()), bookedAt, intent.GetAttributes())
 	if err != nil {
+		s.logger.Warn("Failed to resolve fee rule", zap.Error(err))
 		switch {
 		case errors.Is(err, merrors.ErrNoData):
-			return nil, nil, nil, status.Error(codes.NotFound, "fee rule not found")
+			return nil, nil, nil, status.Error(codes.NotFound, fmt.Sprintf("fee rule not found: %s", err.Error()))
 		case errors.Is(err, merrors.ErrDataConflict):
-			return nil, nil, nil, status.Error(codes.FailedPrecondition, "conflicting fee rules")
+			return nil, nil, nil, status.Error(codes.FailedPrecondition, fmt.Sprintf("conflicting fee rules: %s", err.Error()))
 		case errors.Is(err, storage.ErrConflictingFeePlans):
-			return nil, nil, nil, status.Error(codes.FailedPrecondition, "conflicting fee plans")
+			return nil, nil, nil, status.Error(codes.FailedPrecondition, fmt.Sprintf("conflicting fee plans: %s", err.Error()))
 		case errors.Is(err, storage.ErrFeePlanNotFound):
-			return nil, nil, nil, status.Error(codes.NotFound, "fee plan not found")
+			return nil, nil, nil, status.Error(codes.NotFound, fmt.Sprintf("fee plan not found: %s", err.Error()))
 		default:
-			logger.Warn("failed to resolve fee rule", zap.Error(err))
-			return nil, nil, nil, status.Error(codes.Internal, "failed to resolve fee rule")
+			return nil, nil, nil, status.Error(codes.Internal, fmt.Sprintf("failed to resolve fee rule: %s", err.Error()))
 		}
 	}
 

api/payments/orchestrator/internal/service/orchestrator/payment_plan_ledger.go

@@ -81,7 +81,7 @@ func (p *paymentExecutor) postLedgerBlock(ctx context.Context, payment *model.Pa
 	if err != nil {
 		return "", err
 	}
-	blockAccount, err := ledgerBlockAccount(payment)
+	blockAccount, err := p.resolveLedgerBlockAccount(ctx, payment, amount)
 	if err != nil {
 		return "", err
 	}
@@ -139,7 +139,7 @@ func (p *paymentExecutor) postLedgerRelease(ctx context.Context, payment *model.
 	if err != nil {
 		return "", err
 	}
-	blockAccount, err := ledgerBlockAccount(payment)
+	blockAccount, err := p.resolveLedgerBlockAccount(ctx, payment, amount)
 	if err != nil {
 		return "", err
 	}
@@ -441,6 +441,23 @@ func setLedgerAccountAttributes(payment *model.Payment, accountRef string) {
 	}
 }
 
+func setLedgerBlockAccountAttributes(payment *model.Payment, accountRef string) {
+	if payment == nil || strings.TrimSpace(accountRef) == "" {
+		return
+	}
+	if payment.Intent.Attributes == nil {
+		payment.Intent.Attributes = map[string]string{}
+	}
+	if attributeLookup(payment.Intent.Attributes,
+		"ledger_block_account_ref",
+		"ledgerBlockAccountRef",
+		"ledger_hold_account_ref",
+		"ledgerHoldAccountRef",
+	) == "" {
+		payment.Intent.Attributes["ledger_block_account_ref"] = accountRef
+	}
+}
+
 func ledgerDebitAccount(payment *model.Payment) (string, string, error) {
 	if payment == nil {
 		return "", "", merrors.InvalidArgument("ledger: payment is required")
@@ -483,6 +500,24 @@ func ledgerBlockAccount(payment *model.Payment) (string, error) {
 	return "", merrors.InvalidArgument("ledger: block account is required")
 }
 
+func (p *paymentExecutor) resolveLedgerBlockAccount(ctx context.Context, payment *model.Payment, amount *moneyv1.Money) (string, error) {
+	if payment == nil {
+		return "", merrors.InvalidArgument("ledger: payment is required")
+	}
+	if amount == nil || strings.TrimSpace(amount.GetCurrency()) == "" {
+		return "", merrors.InvalidArgument("ledger: amount is required")
+	}
+	if ref, err := ledgerBlockAccount(payment); err == nil && strings.TrimSpace(ref) != "" {
+		return ref, nil
+	}
+	account, err := p.resolveOrgOwnedLedgerAccount(ctx, payment, amount)
+	if err != nil {
+		return "", err
+	}
+	setLedgerBlockAccountAttributes(payment, account)
+	return account, nil
+}
+
 func ledgerBlockAccountIfConfirmed(payment *model.Payment) string {
 	if payment == nil {
 		return ""