diff --git a/api/payments/orchestrator/internal/service/orchestrator/handlers_commands.go b/api/payments/orchestrator/internal/service/orchestrator/handlers_commands.go index 5da87dc..6818401 100644 --- a/api/payments/orchestrator/internal/service/orchestrator/handlers_commands.go +++ b/api/payments/orchestrator/internal/service/orchestrator/handlers_commands.go @@ -12,6 +12,7 @@ import ( "github.com/tech/sendico/pkg/merrors" "github.com/tech/sendico/pkg/mlogger" "github.com/tech/sendico/pkg/mservice" + "github.com/tech/sendico/pkg/mutil/mzap" orchestratorv1 "github.com/tech/sendico/pkg/proto/payments/orchestrator/v1" "go.mongodb.org/mongo-driver/bson/primitive" "go.uber.org/zap" @@ -61,7 +62,13 @@ func (h *quotePaymentCommand) Execute(ctx context.Context, req *orchestratorv1.Q if err := quotesStore.Create(ctx, record); err != nil { return gsresponse.Auto[orchestratorv1.QuotePaymentResponse](h.logger, mservice.PaymentOrchestrator, err) } - h.logger.Info("Stored payment quote", zap.String("quote_ref", quoteRef), zap.String("org_ref", orgID.Hex())) + h.logger.Info( + "Stored payment quote", + zap.String("quote_ref", quoteRef), + mzap.ObjRef("org_ref", orgID), + zap.String("idempotency_key", strings.TrimSpace(req.GetIdempotencyKey())), + zap.String("kind", intent.GetKind().String()), + ) } return gsresponse.Success(&orchestratorv1.QuotePaymentResponse{Quote: quote}) @@ -79,7 +86,7 @@ func (h *quotePaymentsCommand) Execute(ctx context.Context, req *orchestratorv1. if req == nil { return gsresponse.InvalidArgument[orchestratorv1.QuotePaymentsResponse](h.logger, mservice.PaymentOrchestrator, merrors.InvalidArgument("nil request")) } - orgRef, orgID, err := validateMetaAndOrgRef(req.GetMeta()) + orgID, orgRef, err := validateMetaAndOrgRef(req.GetMeta()) if err != nil { return gsresponse.InvalidArgument[orchestratorv1.QuotePaymentsResponse](h.logger, mservice.PaymentOrchestrator, err) } @@ -101,7 +108,7 @@ func (h *quotePaymentsCommand) Execute(ctx context.Context, req *orchestratorv1. Intent: intent, PreviewOnly: req.GetPreviewOnly(), } - quote, expiresAt, err := h.engine.BuildPaymentQuote(ctx, orgRef, quoteReq) + quote, expiresAt, err := h.engine.BuildPaymentQuote(ctx, orgID, quoteReq) if err != nil { return gsresponse.Auto[orchestratorv1.QuotePaymentsResponse](h.logger, mservice.PaymentOrchestrator, err) } @@ -132,11 +139,17 @@ func (h *quotePaymentsCommand) Execute(ctx context.Context, req *orchestratorv1. ExpiresAt: expiresAt, } record.SetID(primitive.NewObjectID()) - record.SetOrganizationRef(orgID) + record.SetOrganizationRef(orgRef) if err := quotesStore.Create(ctx, record); err != nil { return gsresponse.Auto[orchestratorv1.QuotePaymentsResponse](h.logger, mservice.PaymentOrchestrator, err) } - h.logger.Info("stored payment quotes", zap.String("quote_ref", quoteRef), zap.String("org_ref", orgID.Hex())) + h.logger.Info( + "stored payment quotes", + zap.String("quote_ref", quoteRef), + mzap.ObjRef("org_ref", orgRef), + zap.String("idempotency_key", baseKey), + zap.Int("quote_count", len(quotes)), + ) } return gsresponse.Success(&orchestratorv1.QuotePaymentsResponse{ @@ -158,7 +171,7 @@ func (h *initiatePaymentsCommand) Execute(ctx context.Context, req *orchestrator if req == nil { return gsresponse.InvalidArgument[orchestratorv1.InitiatePaymentsResponse](h.logger, mservice.PaymentOrchestrator, merrors.InvalidArgument("nil request")) } - _, orgID, err := validateMetaAndOrgRef(req.GetMeta()) + _, orgRef, err := validateMetaAndOrgRef(req.GetMeta()) if err != nil { return gsresponse.InvalidArgument[orchestratorv1.InitiatePaymentsResponse](h.logger, mservice.PaymentOrchestrator, err) } @@ -175,7 +188,7 @@ func (h *initiatePaymentsCommand) Execute(ctx context.Context, req *orchestrator if err != nil { return gsresponse.Unavailable[orchestratorv1.InitiatePaymentsResponse](h.logger, mservice.PaymentOrchestrator, err) } - record, err := quotesStore.GetByRef(ctx, orgID, quoteRef) + record, err := quotesStore.GetByRef(ctx, orgRef, quoteRef) if err != nil { if errors.Is(err, storage.ErrQuoteNotFound) { return gsresponse.FailedPrecondition[orchestratorv1.InitiatePaymentsResponse](h.logger, mservice.PaymentOrchestrator, "quote_not_found", merrors.InvalidArgument("quote_ref not found or expired")) @@ -213,14 +226,14 @@ func (h *initiatePaymentsCommand) Execute(ctx context.Context, req *orchestrator quoteProto.QuoteRef = quoteRef perKey := perIntentIdempotencyKey(idempotencyKey, i, len(intents)) - if existing, err := getPaymentByIdempotencyKey(ctx, store, orgID, perKey); err == nil && existing != nil { + if existing, err := getPaymentByIdempotencyKey(ctx, store, orgRef, perKey); err == nil && existing != nil { payments = append(payments, toProtoPayment(existing)) continue } else if err != nil && !errors.Is(err, storage.ErrPaymentNotFound) { return gsresponse.Auto[orchestratorv1.InitiatePaymentsResponse](h.logger, mservice.PaymentOrchestrator, err) } - entity := newPayment(orgID, intentProto, perKey, req.GetMetadata(), quoteProto) + entity := newPayment(orgRef, intentProto, perKey, req.GetMetadata(), quoteProto) if err = store.Create(ctx, entity); err != nil { if errors.Is(err, storage.ErrDuplicatePayment) { return gsresponse.Auto[orchestratorv1.InitiatePaymentsResponse](h.logger, mservice.PaymentOrchestrator, merrors.DataConflict("payment already exists")) @@ -235,6 +248,13 @@ func (h *initiatePaymentsCommand) Execute(ctx context.Context, req *orchestrator payments = append(payments, toProtoPayment(entity)) } + h.logger.Info( + "Payments initiated", + mzap.ObjRef("org_ref", orgRef), + zap.String("quote_ref", quoteRef), + zap.String("idempotency_key", idempotencyKey), + zap.Int("payment_count", len(payments)), + ) return gsresponse.Success(&orchestratorv1.InitiatePaymentsResponse{Payments: payments}) } @@ -273,6 +293,13 @@ func (h *initiatePaymentCommand) Execute(ctx context.Context, req *orchestratorv if err != nil { return gsresponse.InvalidArgument[orchestratorv1.InitiatePaymentResponse](h.logger, mservice.PaymentOrchestrator, err) } + h.logger.Debug( + "Initiate payment request accepted", + zap.String("org_ref", orgID.Hex()), + zap.String("idempotency_key", idempotencyKey), + zap.String("quote_ref", quoteRef), + zap.Bool("has_intent", hasIntent), + ) store, err := ensurePaymentsStore(h.engine.Repository()) if err != nil { @@ -280,7 +307,13 @@ func (h *initiatePaymentCommand) Execute(ctx context.Context, req *orchestratorv } if existing, err := getPaymentByIdempotencyKey(ctx, store, orgID, idempotencyKey); err == nil && existing != nil { - h.logger.Debug("idempotent payment request reused", zap.String("payment_ref", existing.PaymentRef), zap.String("org_ref", orgID.Hex())) + h.logger.Debug( + "idempotent payment request reused", + zap.String("payment_ref", existing.PaymentRef), + zap.String("org_ref", orgID.Hex()), + zap.String("idempotency_key", idempotencyKey), + zap.String("quote_ref", quoteRef), + ) return gsresponse.Success(&orchestratorv1.InitiatePaymentResponse{Payment: toProtoPayment(existing)}) } else if err != nil && !errors.Is(err, storage.ErrPaymentNotFound) { return gsresponse.Auto[orchestratorv1.InitiatePaymentResponse](h.logger, mservice.PaymentOrchestrator, err) @@ -315,6 +348,12 @@ func (h *initiatePaymentCommand) Execute(ctx context.Context, req *orchestratorv if err := requireNonNilIntent(resolvedIntent); err != nil { return gsresponse.InvalidArgument[orchestratorv1.InitiatePaymentResponse](h.logger, mservice.PaymentOrchestrator, err) } + h.logger.Debug( + "Payment quote resolved", + zap.String("org_ref", orgID.Hex()), + zap.String("quote_ref", quoteRef), + zap.Bool("quote_ref_used", quoteRef != ""), + ) entity := newPayment(orgID, resolvedIntent, idempotencyKey, req.GetMetadata(), quoteSnapshot) @@ -329,7 +368,14 @@ func (h *initiatePaymentCommand) Execute(ctx context.Context, req *orchestratorv return gsresponse.Auto[orchestratorv1.InitiatePaymentResponse](h.logger, mservice.PaymentOrchestrator, err) } - h.logger.Info("Payment initiated", zap.String("payment_ref", entity.PaymentRef), zap.String("org_ref", orgID.Hex()), zap.String("kind", resolvedIntent.GetKind().String())) + h.logger.Info( + "Payment initiated", + zap.String("payment_ref", entity.PaymentRef), + zap.String("org_ref", orgID.Hex()), + zap.String("kind", resolvedIntent.GetKind().String()), + zap.String("quote_ref", quoteSnapshot.GetQuoteRef()), + zap.String("idempotency_key", idempotencyKey), + ) return gsresponse.Success(&orchestratorv1.InitiatePaymentResponse{ Payment: toProtoPayment(entity), })