killbill-memoizeit

payment: improve logging for invoice payments and retries See

7/6/2016 1:24:01 PM

Details

diff --git a/payment/src/main/java/org/killbill/billing/payment/api/DefaultPaymentApi.java b/payment/src/main/java/org/killbill/billing/payment/api/DefaultPaymentApi.java
index 5bfd18d..22f3a2a 100644
--- a/payment/src/main/java/org/killbill/billing/payment/api/DefaultPaymentApi.java
+++ b/payment/src/main/java/org/killbill/billing/payment/api/DefaultPaymentApi.java
@@ -47,9 +47,10 @@ import com.google.common.base.Predicate;
 import com.google.common.collect.Iterables;
 import com.google.common.collect.Lists;
 
-public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
+import static org.killbill.billing.payment.logging.PaymentLoggingHelper.logEnterAPICall;
+import static org.killbill.billing.payment.logging.PaymentLoggingHelper.logExitAPICall;
 
-    private static final Joiner JOINER = Joiner.on(",");
+public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
     private static final boolean SHOULD_LOCK_ACCOUNT = true;
     private static final boolean IS_API_PAYMENT = true;
@@ -84,7 +85,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, paymentMethodId, paymentId, null, amount, currency, paymentExternalKey, paymentTransactionExternalKey, null, null);
+            logEnterAPICall(log, transactionType, account, paymentMethodId, paymentId, null, amount, currency, paymentExternalKey, paymentTransactionExternalKey, null, null);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = paymentProcessor.createAuthorization(IS_API_PAYMENT, NULL_ATTEMPT_ID, account, paymentMethodId, paymentId, amount, currency, paymentExternalKey, paymentTransactionExternalKey,
@@ -94,7 +95,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -130,7 +132,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, paymentMethodId, paymentId, null, amount, currency, paymentExternalKey, paymentTransactionExternalKey, null, paymentControlPluginNames);
+            logEnterAPICall(log, transactionType, account, paymentMethodId, paymentId, null, amount, currency, paymentExternalKey, paymentTransactionExternalKey, null, paymentControlPluginNames);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = pluginControlPaymentProcessor.createAuthorization(IS_API_PAYMENT, account, paymentMethodId, paymentId, amount, currency, paymentExternalKey, paymentTransactionExternalKey,
@@ -140,7 +142,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -168,7 +171,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, null, paymentId, null, amount, currency, null, paymentTransactionExternalKey, null, null);
+            logEnterAPICall(log, transactionType, account, null, paymentId, null, amount, currency, null, paymentTransactionExternalKey, null, null);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = paymentProcessor.createCapture(IS_API_PAYMENT, NULL_ATTEMPT_ID, account, paymentId, amount, currency, paymentTransactionExternalKey,
@@ -178,7 +181,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -210,7 +214,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, null, paymentId, null, amount, currency, null, paymentTransactionExternalKey, null, paymentControlPluginNames);
+            logEnterAPICall(log, transactionType, account, null, paymentId, null, amount, currency, null, paymentTransactionExternalKey, null, paymentControlPluginNames);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = pluginControlPaymentProcessor.createCapture(IS_API_PAYMENT, account, paymentId, amount, currency, paymentTransactionExternalKey,
@@ -220,7 +224,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -250,7 +255,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, paymentMethodId, paymentId, null, amount, currency, paymentExternalKey, paymentTransactionExternalKey, null, null);
+            logEnterAPICall(log, transactionType, account, paymentMethodId, paymentId, null, amount, currency, paymentExternalKey, paymentTransactionExternalKey, null, null);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = paymentProcessor.createPurchase(IS_API_PAYMENT, NULL_ATTEMPT_ID, account, paymentMethodId, paymentId, amount, currency, paymentExternalKey, paymentTransactionExternalKey,
@@ -260,7 +265,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -303,7 +309,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         PaymentTransaction paymentTransaction = null;
 
         try {
-            logEnterAPICall(transactionType, account, paymentMethodId, paymentId, null, amount, currency, paymentExternalKey, paymentTransactionExternalKey, null, paymentControlPluginNames);
+            logEnterAPICall(log, transactionType, account, paymentMethodId, paymentId, null, amount, currency, paymentExternalKey, paymentTransactionExternalKey, null, paymentControlPluginNames);
 
             payment = pluginControlPaymentProcessor.createPurchase(IS_API_PAYMENT, account, nonNulPaymentMethodId, paymentId, amount, currency, paymentExternalKey, paymentTransactionExternalKey,
                                                                                  properties, paymentControlPluginNames, callContext, internalCallContext);
@@ -312,7 +318,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -338,7 +345,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, null, paymentId, null, null, null, null, paymentTransactionExternalKey, null, null);
+            logEnterAPICall(log, transactionType, account, null, paymentId, null, null, null, null, paymentTransactionExternalKey, null, null);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = paymentProcessor.createVoid(IS_API_PAYMENT, NULL_ATTEMPT_ID, account, paymentId, paymentTransactionExternalKey,
@@ -348,7 +355,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -378,7 +386,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, null, paymentId, null, null, null, null, paymentTransactionExternalKey, null, paymentControlPluginNames);
+            logEnterAPICall(log, transactionType, account, null, paymentId, null, null, null, null, paymentTransactionExternalKey, null, paymentControlPluginNames);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = pluginControlPaymentProcessor.createVoid(IS_API_PAYMENT, account, paymentId, paymentTransactionExternalKey,
@@ -388,7 +396,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -416,7 +425,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, null, paymentId, null, amount, currency, null, paymentTransactionExternalKey, null, null);
+            logEnterAPICall(log, transactionType, account, null, paymentId, null, amount, currency, null, paymentTransactionExternalKey, null, null);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = paymentProcessor.createRefund(IS_API_PAYMENT, NULL_ATTEMPT_ID, account, paymentId, amount, currency, paymentTransactionExternalKey,
@@ -426,7 +435,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -460,7 +470,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, null, paymentId, null, amount, currency, null, paymentTransactionExternalKey, null, paymentControlPluginNames);
+            logEnterAPICall(log, transactionType, account, null, paymentId, null, amount, currency, null, paymentTransactionExternalKey, null, paymentControlPluginNames);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = pluginControlPaymentProcessor.createRefund(IS_API_PAYMENT, account, paymentId, amount, currency, paymentTransactionExternalKey,
@@ -470,7 +480,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -500,7 +511,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, paymentMethodId, paymentId, null, amount, currency, paymentExternalKey, paymentTransactionExternalKey, null, null);
+            logEnterAPICall(log, transactionType, account, paymentMethodId, paymentId, null, amount, currency, paymentExternalKey, paymentTransactionExternalKey, null, null);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = paymentProcessor.createCredit(IS_API_PAYMENT, NULL_ATTEMPT_ID, account, paymentMethodId, paymentId, amount, currency, paymentExternalKey, paymentTransactionExternalKey,
@@ -510,7 +521,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -545,7 +557,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, paymentMethodId, paymentId, null, amount, currency, paymentExternalKey, paymentTransactionExternalKey, null, paymentControlPluginNames);
+            logEnterAPICall(log, transactionType, account, paymentMethodId, paymentId, null, amount, currency, paymentExternalKey, paymentTransactionExternalKey, null, paymentControlPluginNames);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = pluginControlPaymentProcessor.createCredit(IS_API_PAYMENT, account, paymentMethodId, paymentId, amount, currency, paymentExternalKey, paymentTransactionExternalKey,
@@ -555,7 +567,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -578,7 +591,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, null, null, paymentTransactionId, null, null, null, null, null, null);
+            logEnterAPICall(log, transactionType, account, null, null, paymentTransactionId, null, null, null, null, null, null);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = paymentProcessor.notifyPendingPaymentOfStateChanged(account, paymentTransactionId, isSuccess, callContext, internalCallContext);
@@ -592,7 +605,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
                                                                                                 }).orNull();
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -622,7 +636,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, null, paymentId, null, amount, currency, null, paymentTransactionExternalKey, null, null);
+            logEnterAPICall(log, transactionType, account, null, paymentId, null, amount, currency, null, paymentTransactionExternalKey, null, null);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = paymentProcessor.createChargeback(IS_API_PAYMENT, NULL_ATTEMPT_ID, account, paymentId, paymentTransactionExternalKey, amount, currency, true,
@@ -632,7 +646,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -662,7 +677,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, null, paymentId, null, amount, currency, null, paymentTransactionExternalKey, null, paymentControlPluginNames);
+            logEnterAPICall(log, transactionType, account, null, paymentId, null, amount, currency, null, paymentTransactionExternalKey, null, paymentControlPluginNames);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = pluginControlPaymentProcessor.createChargeback(IS_API_PAYMENT, account, paymentId, paymentTransactionExternalKey, amount, currency,
@@ -672,7 +687,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -696,7 +712,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, null, paymentId, null, null, null, null, paymentTransactionExternalKey, null, null);
+            logEnterAPICall(log, transactionType, account, null, paymentId, null, null, null, null, paymentTransactionExternalKey, null, null);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = paymentProcessor.createChargebackReversal(IS_API_PAYMENT, NULL_ATTEMPT_ID, account, paymentId, paymentTransactionExternalKey, null, null, true, callContext, internalCallContext);
@@ -705,7 +721,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -734,7 +751,7 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
         Payment payment = null;
         PaymentTransaction paymentTransaction = null;
         try {
-            logEnterAPICall(transactionType, account, null, paymentId, null, null, null, null, paymentTransactionExternalKey, null, paymentControlPluginNames);
+            logEnterAPICall(log, transactionType, account, null, paymentId, null, null, null, null, paymentTransactionExternalKey, null, paymentControlPluginNames);
 
             final InternalCallContext internalCallContext = internalCallContextFactory.createInternalCallContext(account.getId(), callContext);
             payment = pluginControlPaymentProcessor.createChargebackReversal(IS_API_PAYMENT, account, paymentId, paymentTransactionExternalKey, paymentControlPluginNames, callContext, internalCallContext);
@@ -750,7 +767,8 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
 
             return payment;
         } finally {
-            logExitAPICall(transactionType,
+            logExitAPICall(log,
+                           transactionType,
                            account,
                            payment != null ? payment.getPaymentMethodId() : null,
                            payment != null ? payment.getId() : null,
@@ -900,122 +918,4 @@ public class DefaultPaymentApi extends DefaultApiBase implements PaymentApi {
                                                       });
         }
     }
-
-    private void logEnterAPICall(final String transactionType,
-                                   final Account account,
-                                   @Nullable final UUID paymentMethodId,
-                                   @Nullable final UUID paymentId,
-                                   @Nullable final UUID transactionId,
-                                   @Nullable final BigDecimal amount,
-                                   @Nullable final Currency currency,
-                                   @Nullable final String paymentExternalKey,
-                                   @Nullable final String paymentTransactionExternalKey,
-                                   @Nullable final TransactionStatus transactionStatus,
-                                   @Nullable final List<String> paymentControlPluginNames) {
-        logAPICallInternal("ENTERING ",
-                           transactionType,
-                           account,
-                           paymentMethodId,
-                           paymentId,
-                           transactionId,
-                           amount,
-                           currency,
-                           paymentExternalKey,
-                           paymentTransactionExternalKey,
-                           transactionStatus,
-                           paymentControlPluginNames);
-    }
-
-    private void logExitAPICall(final String transactionType,
-                                  final Account account,
-                                  @Nullable final UUID paymentMethodId,
-                                  @Nullable final UUID paymentId,
-                                  @Nullable final UUID transactionId,
-                                  @Nullable final BigDecimal amount,
-                                  @Nullable final Currency currency,
-                                  @Nullable final String paymentExternalKey,
-                                  @Nullable final String paymentTransactionExternalKey,
-                                  @Nullable final TransactionStatus transactionStatus,
-                                  @Nullable final List<String> paymentControlPluginNames) {
-        logAPICallInternal("EXITING ",
-                           transactionType,
-                           account,
-                           paymentMethodId,
-                           paymentId,
-                           transactionId,
-                           amount,
-                           currency,
-                           paymentExternalKey,
-                           paymentTransactionExternalKey,
-                           transactionStatus,
-                           paymentControlPluginNames);
-    }
-
-    private void logAPICallInternal(final String prefixMsg,
-                                    final String transactionType,
-                                    final Account account,
-                                    final UUID paymentMethodId,
-                                    @Nullable final UUID paymentId,
-                                    @Nullable final UUID transactionId,
-                                    @Nullable final BigDecimal amount,
-                                    @Nullable final Currency currency,
-                                    @Nullable final String paymentExternalKey,
-                                    @Nullable final String paymentTransactionExternalKey,
-                                    @Nullable final TransactionStatus transactionStatus,
-                                    @Nullable final List<String> paymentControlPluginNames) {
-        if (log.isInfoEnabled()) {
-            final StringBuilder logLine = new StringBuilder(prefixMsg);
-            logLine.append("PaymentApi: transactionType='")
-                   .append(transactionType)
-                   .append("', accountId='")
-                   .append(account.getId())
-                   .append("'");
-            if (paymentMethodId != null) {
-                logLine.append(", paymentMethodId='")
-                       .append(paymentMethodId)
-                       .append("'");
-            }
-            if (paymentExternalKey != null) {
-                logLine.append(", paymentExternalKey='")
-                       .append(paymentExternalKey)
-                       .append("'");
-            }
-            if (paymentTransactionExternalKey != null) {
-                logLine.append(", paymentTransactionExternalKey='")
-                       .append(paymentTransactionExternalKey)
-                       .append("'");
-            }
-            if (paymentId != null) {
-                logLine.append(", paymentId='")
-                       .append(paymentId)
-                       .append("'");
-            }
-            if (transactionId != null) {
-                logLine.append(", transactionId='")
-                       .append(transactionId)
-                       .append("'");
-            }
-            if (amount != null) {
-                logLine.append(", amount='")
-                       .append(amount)
-                       .append("'");
-            }
-            if (currency != null) {
-                logLine.append(", currency='")
-                       .append(currency)
-                       .append("'");
-            }
-            if (transactionStatus != null) {
-                logLine.append(", transactionStatus='")
-                       .append(transactionStatus)
-                       .append("'");
-            }
-            if (paymentControlPluginNames != null) {
-                logLine.append(", paymentControlPluginNames='")
-                       .append(JOINER.join(paymentControlPluginNames))
-                       .append("'");
-            }
-            log.info(logLine.toString());
-        }
-    }
 }
diff --git a/payment/src/main/java/org/killbill/billing/payment/bus/PaymentBusEventHandler.java b/payment/src/main/java/org/killbill/billing/payment/bus/PaymentBusEventHandler.java
index 145507a..fd9cebe 100644
--- a/payment/src/main/java/org/killbill/billing/payment/bus/PaymentBusEventHandler.java
+++ b/payment/src/main/java/org/killbill/billing/payment/bus/PaymentBusEventHandler.java
@@ -1,7 +1,7 @@
 /*
  * Copyright 2010-2013 Ning, Inc.
- * Copyright 2014-2015 Groupon, Inc
- * Copyright 2014-2015 The Billing Project, LLC
+ * Copyright 2014-2016 Groupon, Inc
+ * Copyright 2014-2016 The Billing Project, LLC
  *
  * The Billing Project licenses this file to you under the Apache License, version 2.0
  * (the "License"); you may not use this file except in compliance with the
@@ -20,6 +20,7 @@ package org.killbill.billing.payment.bus;
 
 import java.math.BigDecimal;
 import java.util.ArrayList;
+import java.util.Collection;
 import java.util.LinkedList;
 import java.util.List;
 
@@ -30,8 +31,11 @@ import org.killbill.billing.account.api.AccountInternalApi;
 import org.killbill.billing.callcontext.InternalCallContext;
 import org.killbill.billing.events.InvoiceCreationInternalEvent;
 import org.killbill.billing.events.PaymentInternalEvent;
+import org.killbill.billing.payment.api.Payment;
 import org.killbill.billing.payment.api.PaymentApiException;
+import org.killbill.billing.payment.api.PaymentTransaction;
 import org.killbill.billing.payment.api.PluginProperty;
+import org.killbill.billing.payment.api.TransactionType;
 import org.killbill.billing.payment.core.PluginControlPaymentProcessor;
 import org.killbill.billing.payment.core.janitor.Janitor;
 import org.killbill.billing.payment.invoice.InvoicePaymentControlPluginApi;
@@ -44,10 +48,16 @@ import org.killbill.billing.util.config.definition.PaymentConfig;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
+import com.google.common.base.Predicate;
+import com.google.common.collect.Iterables;
+import com.google.common.collect.Lists;
 import com.google.common.eventbus.AllowConcurrentEvents;
 import com.google.common.eventbus.Subscribe;
 import com.google.inject.Inject;
 
+import static org.killbill.billing.payment.logging.PaymentLoggingHelper.logEnterAPICall;
+import static org.killbill.billing.payment.logging.PaymentLoggingHelper.logExitAPICall;
+
 public class PaymentBusEventHandler {
 
     private static final Logger log = LoggerFactory.getLogger(PaymentBusEventHandler.class);
@@ -82,22 +92,49 @@ public class PaymentBusEventHandler {
     public void processInvoiceEvent(final InvoiceCreationInternalEvent event) {
         log.info("Received invoice creation notification for accountId='{}', invoiceId='{}'", event.getAccountId(), event.getInvoiceId());
 
-        final Account account;
-        try {
-            final InternalCallContext internalContext = internalCallContextFactory.createInternalCallContext(event.getSearchKey2(), event.getSearchKey1(), "PaymentRequestProcessor", CallOrigin.INTERNAL, UserType.SYSTEM, event.getUserToken());
-            account = accountApi.getAccountById(event.getAccountId(), internalContext);
+        final Collection<PluginProperty> properties = new ArrayList<PluginProperty>();
+        final PluginProperty propertyInvoiceId = new PluginProperty(InvoicePaymentControlPluginApi.PROP_IPCD_INVOICE_ID, event.getInvoiceId().toString(), false);
+        properties.add(propertyInvoiceId);
+
+        final InternalCallContext internalContext = internalCallContextFactory.createInternalCallContext(event.getSearchKey2(), event.getSearchKey1(), "PaymentRequestProcessor", CallOrigin.INTERNAL, UserType.SYSTEM, event.getUserToken());
+        final CallContext callContext = internalCallContextFactory.createCallContext(internalContext);
 
-            final List<PluginProperty> properties = new ArrayList<PluginProperty>();
-            final PluginProperty prop1 = new PluginProperty(InvoicePaymentControlPluginApi.PROP_IPCD_INVOICE_ID, event.getInvoiceId().toString(), false);
-            properties.add(prop1);
+        final BigDecimal amountToBePaid = null; // We let the plugin compute how much should be paid
+        final List<String> paymentControlPluginNames = paymentConfig.getPaymentControlPluginNames(internalContext) != null ? new LinkedList<String>(paymentConfig.getPaymentControlPluginNames(internalContext)) : new LinkedList<String>();
+        paymentControlPluginNames.add(InvoicePaymentControlPluginApi.PLUGIN_NAME);
 
-            final CallContext callContext = internalCallContextFactory.createCallContext(internalContext);
+        final String paymentExternalKey = UUIDs.randomUUID().toString();
+        final String paymentTransactionExternalKey = UUIDs.randomUUID().toString();
+
+        final String transactionType = TransactionType.PURCHASE.name();
+        Account account = null;
+        Payment payment = null;
+        PaymentTransaction paymentTransaction = null;
+        try {
+            account = accountApi.getAccountById(event.getAccountId(), internalContext);
 
-            final BigDecimal amountToBePaid = null; // We let the plugin compute how much should be paid
-            final List<String> paymentControlPluginNames = paymentConfig.getPaymentControlPluginNames(internalContext) != null ? new LinkedList<String>(paymentConfig.getPaymentControlPluginNames(internalContext)) : new LinkedList<String>();
-            paymentControlPluginNames.add(InvoicePaymentControlPluginApi.PLUGIN_NAME);
-            pluginControlPaymentProcessor.createPurchase(false, account, account.getPaymentMethodId(), null, amountToBePaid, account.getCurrency(), UUIDs.randomUUID().toString(), UUIDs.randomUUID().toString(),
-                                                         properties, paymentControlPluginNames, callContext, internalContext);
+            logEnterAPICall(log,
+                            transactionType,
+                            account,
+                            account.getPaymentMethodId(),
+                            null,
+                            null,
+                            amountToBePaid,
+                            account.getCurrency(),
+                            paymentExternalKey,
+                            paymentTransactionExternalKey,
+                            null,
+                            paymentControlPluginNames);
+
+            payment = pluginControlPaymentProcessor.createPurchase(false, account, account.getPaymentMethodId(), null, amountToBePaid, account.getCurrency(), paymentExternalKey, paymentTransactionExternalKey, properties, paymentControlPluginNames, callContext, internalContext);
+
+            paymentTransaction = Iterables.<PaymentTransaction>find(Lists.<PaymentTransaction>reverse(payment.getTransactions()),
+                                                                    new Predicate<PaymentTransaction>() {
+                                                                        @Override
+                                                                        public boolean apply(final PaymentTransaction input) {
+                                                                            return paymentTransactionExternalKey.equals(input.getExternalKey());
+                                                                        }
+                                                                    });
         } catch (final AccountApiException e) {
             log.warn("Failed to process invoice payment", e);
         } catch (final PaymentApiException e) {
@@ -105,6 +142,19 @@ public class PaymentBusEventHandler {
             if (e.getCode() != ErrorCode.PAYMENT_PLUGIN_API_ABORTED.getCode()) {
                 log.warn("Failed to process invoice payment {}", e.toString());
             }
+        } finally {
+            logExitAPICall(log,
+                           transactionType,
+                           account,
+                           payment != null ? payment.getPaymentMethodId() : null,
+                           payment != null ? payment.getId() : null,
+                           paymentTransaction != null ? paymentTransaction.getId() : null,
+                           paymentTransaction != null ? paymentTransaction.getProcessedAmount() : null,
+                           paymentTransaction != null ? paymentTransaction.getProcessedCurrency() : null,
+                           payment != null ? payment.getExternalKey() : null,
+                           paymentTransaction != null ? paymentTransaction.getExternalKey() : null,
+                           paymentTransaction != null ? paymentTransaction.getTransactionStatus() : null,
+                           paymentControlPluginNames);
         }
     }
 }
diff --git a/payment/src/main/java/org/killbill/billing/payment/core/PluginControlPaymentProcessor.java b/payment/src/main/java/org/killbill/billing/payment/core/PluginControlPaymentProcessor.java
index 9ace343..b1dffa6 100644
--- a/payment/src/main/java/org/killbill/billing/payment/core/PluginControlPaymentProcessor.java
+++ b/payment/src/main/java/org/killbill/billing/payment/core/PluginControlPaymentProcessor.java
@@ -36,6 +36,7 @@ import org.killbill.billing.invoice.api.InvoiceInternalApi;
 import org.killbill.billing.osgi.api.OSGIServiceRegistration;
 import org.killbill.billing.payment.api.Payment;
 import org.killbill.billing.payment.api.PaymentApiException;
+import org.killbill.billing.payment.api.PaymentTransaction;
 import org.killbill.billing.payment.api.PluginProperty;
 import org.killbill.billing.payment.api.TransactionType;
 import org.killbill.billing.payment.core.sm.PaymentControlStateMachineHelper;
@@ -56,7 +57,13 @@ import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
 import com.google.common.base.Joiner;
+import com.google.common.base.Predicate;
 import com.google.common.collect.ImmutableList;
+import com.google.common.collect.Iterables;
+import com.google.common.collect.Lists;
+
+import static org.killbill.billing.payment.logging.PaymentLoggingHelper.logEnterAPICall;
+import static org.killbill.billing.payment.logging.PaymentLoggingHelper.logExitAPICall;
 
 public class PluginControlPaymentProcessor extends ProcessorBase {
 
@@ -225,36 +232,60 @@ public class PluginControlPaymentProcessor extends ProcessorBase {
     }
 
     public void retryPaymentTransaction(final UUID attemptId, final List<String> paymentControlPluginNames, final InternalCallContext internalCallContext) {
-        try {
-            final PaymentAttemptModelDao attempt = paymentDao.getPaymentAttempt(attemptId, internalCallContext);
-            final PaymentModelDao payment = paymentDao.getPaymentByExternalKey(attempt.getPaymentExternalKey(), internalCallContext);
-            final UUID paymentId = payment != null ? payment.getId() : null;
+        final PaymentAttemptModelDao attempt = paymentDao.getPaymentAttempt(attemptId, internalCallContext);
+        log.info("Retrying attemptId='{}', paymentExternalKey='{}', transactionExternalKey='{}'. paymentControlPluginNames='{}'",
+                 attemptId, attempt.getPaymentExternalKey(), attempt.getTransactionExternalKey(), paymentControlPluginNames);
 
-            final Iterable<PluginProperty> pluginProperties = PluginPropertySerializer.deserialize(attempt.getPluginProperties());
-            final Account account = accountInternalApi.getAccountById(attempt.getAccountId(), internalCallContext);
-            final CallContext callContext = buildCallContext(internalCallContext);
+        final PaymentModelDao paymentModelDao = paymentDao.getPaymentByExternalKey(attempt.getPaymentExternalKey(), internalCallContext);
+        final UUID paymentId = paymentModelDao != null ? paymentModelDao.getId() : null;
 
+        final CallContext callContext = buildCallContext(internalCallContext);
+
+        final String transactionType = TransactionType.PURCHASE.name();
+        Account account = null;
+        Payment payment = null;
+        PaymentTransaction paymentTransaction = null;
+        try {
+            account = accountInternalApi.getAccountById(attempt.getAccountId(), internalCallContext);
             final State state = paymentControlStateMachineHelper.getState(attempt.getStateName());
+            final Iterable<PluginProperty> pluginProperties = PluginPropertySerializer.deserialize(attempt.getPluginProperties());
 
-            log.debug("Retrying attemptId={}, paymentExternalKey={}, transactionExternalKey={}. paymentControlPluginNames={}, now={}",
-                      attemptId, attempt.getPaymentExternalKey(), attempt.getTransactionExternalKey(), paymentControlPluginNames, clock.getUTCNow());
+            logEnterAPICall(log,
+                            transactionType,
+                            account,
+                            attempt.getPaymentMethodId(),
+                            paymentId,
+                            null,
+                            attempt.getAmount(),
+                            attempt.getCurrency(),
+                            attempt.getPaymentExternalKey(),
+                            attempt.getTransactionExternalKey(),
+                            null,
+                            paymentControlPluginNames);
 
-            pluginControlledPaymentAutomatonRunner.run(state,
-                                                       false,
-                                                       attempt.getTransactionType(),
-                                                       ControlOperation.valueOf(attempt.getTransactionType().toString()),
-                                                       account,
-                                                       attempt.getPaymentMethodId(),
-                                                       paymentId,
-                                                       attempt.getPaymentExternalKey(),
-                                                       attempt.getTransactionExternalKey(),
-                                                       attempt.getAmount(),
-                                                       attempt.getCurrency(),
-                                                       pluginProperties,
-                                                       paymentControlPluginNames,
-                                                       callContext,
-                                                       internalCallContext);
+            payment = pluginControlledPaymentAutomatonRunner.run(state,
+                                                                 false,
+                                                                 attempt.getTransactionType(),
+                                                                 ControlOperation.valueOf(attempt.getTransactionType().toString()),
+                                                                 account,
+                                                                 attempt.getPaymentMethodId(),
+                                                                 paymentId,
+                                                                 attempt.getPaymentExternalKey(),
+                                                                 attempt.getTransactionExternalKey(),
+                                                                 attempt.getAmount(),
+                                                                 attempt.getCurrency(),
+                                                                 pluginProperties,
+                                                                 paymentControlPluginNames,
+                                                                 callContext,
+                                                                 internalCallContext);
 
+            paymentTransaction = Iterables.<PaymentTransaction>find(Lists.<PaymentTransaction>reverse(payment.getTransactions()),
+                                                                    new Predicate<PaymentTransaction>() {
+                                                                        @Override
+                                                                        public boolean apply(final PaymentTransaction input) {
+                                                                            return attempt.getTransactionExternalKey().equals(input.getExternalKey());
+                                                                        }
+                                                                    });
         } catch (final AccountApiException e) {
             log.warn("Failed to retry attemptId='{}', paymentControlPlugins='{}'", attemptId, toPluginNamesOnError(paymentControlPluginNames), e);
         } catch (final PaymentApiException e) {
@@ -263,6 +294,19 @@ public class PluginControlPaymentProcessor extends ProcessorBase {
             log.warn("Failed to retry attemptId='{}', paymentControlPlugins='{}'", attemptId, toPluginNamesOnError(paymentControlPluginNames), e);
         } catch (final MissingEntryException e) {
             log.warn("Failed to retry attemptId='{}', paymentControlPlugins='{}'", attemptId, toPluginNamesOnError(paymentControlPluginNames), e);
+        } finally {
+            logExitAPICall(log,
+                           transactionType,
+                           account,
+                           payment != null ? payment.getPaymentMethodId() : null,
+                           payment != null ? payment.getId() : null,
+                           paymentTransaction != null ? paymentTransaction.getId() : null,
+                           paymentTransaction != null ? paymentTransaction.getProcessedAmount() : null,
+                           paymentTransaction != null ? paymentTransaction.getProcessedCurrency() : null,
+                           payment != null ? payment.getExternalKey() : null,
+                           paymentTransaction != null ? paymentTransaction.getExternalKey() : null,
+                           paymentTransaction != null ? paymentTransaction.getTransactionStatus() : null,
+                           paymentControlPluginNames);
         }
     }
 
diff --git a/payment/src/main/java/org/killbill/billing/payment/logging/PaymentLoggingHelper.java b/payment/src/main/java/org/killbill/billing/payment/logging/PaymentLoggingHelper.java
new file mode 100644
index 0000000..c3ac9c2
--- /dev/null
+++ b/payment/src/main/java/org/killbill/billing/payment/logging/PaymentLoggingHelper.java
@@ -0,0 +1,159 @@
+/*
+ * Copyright 2016 Groupon, Inc
+ * Copyright 2016 The Billing Project, LLC
+ *
+ * The Billing Project licenses this file to you under the Apache License, version 2.0
+ * (the "License"); you may not use this file except in compliance with the
+ * License.  You may obtain a copy of the License at:
+ *
+ *    http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+ * WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.  See the
+ * License for the specific language governing permissions and limitations
+ * under the License.
+ */
+
+package org.killbill.billing.payment.logging;
+
+import java.math.BigDecimal;
+import java.util.List;
+import java.util.UUID;
+
+import javax.annotation.Nullable;
+
+import org.killbill.billing.account.api.Account;
+import org.killbill.billing.catalog.api.Currency;
+import org.killbill.billing.payment.api.TransactionStatus;
+import org.slf4j.Logger;
+
+import com.google.common.base.Joiner;
+
+public abstract class PaymentLoggingHelper {
+
+    private static final Joiner JOINER = Joiner.on(",");
+
+    public static void logEnterAPICall(final Logger log,
+                                       final String transactionType,
+                                       final Account account,
+                                       @Nullable final UUID paymentMethodId,
+                                       @Nullable final UUID paymentId,
+                                       @Nullable final UUID transactionId,
+                                       @Nullable final BigDecimal amount,
+                                       @Nullable final Currency currency,
+                                       @Nullable final String paymentExternalKey,
+                                       @Nullable final String paymentTransactionExternalKey,
+                                       @Nullable final TransactionStatus transactionStatus,
+                                       @Nullable final List<String> paymentControlPluginNames) {
+        logAPICallInternal(log,
+                           "ENTERING ",
+                           transactionType,
+                           account,
+                           paymentMethodId,
+                           paymentId,
+                           transactionId,
+                           amount,
+                           currency,
+                           paymentExternalKey,
+                           paymentTransactionExternalKey,
+                           transactionStatus,
+                           paymentControlPluginNames);
+    }
+
+    public static void logExitAPICall(final Logger log,
+                                      final String transactionType,
+                                      final Account account,
+                                      @Nullable final UUID paymentMethodId,
+                                      @Nullable final UUID paymentId,
+                                      @Nullable final UUID transactionId,
+                                      @Nullable final BigDecimal amount,
+                                      @Nullable final Currency currency,
+                                      @Nullable final String paymentExternalKey,
+                                      @Nullable final String paymentTransactionExternalKey,
+                                      @Nullable final TransactionStatus transactionStatus,
+                                      @Nullable final List<String> paymentControlPluginNames) {
+        logAPICallInternal(log,
+                           "EXITING ",
+                           transactionType,
+                           account,
+                           paymentMethodId,
+                           paymentId,
+                           transactionId,
+                           amount,
+                           currency,
+                           paymentExternalKey,
+                           paymentTransactionExternalKey,
+                           transactionStatus,
+                           paymentControlPluginNames);
+    }
+
+    public static void logAPICallInternal(final Logger log,
+                                          final String prefixMsg,
+                                          final String transactionType,
+                                          final Account account,
+                                          final UUID paymentMethodId,
+                                          @Nullable final UUID paymentId,
+                                          @Nullable final UUID transactionId,
+                                          @Nullable final BigDecimal amount,
+                                          @Nullable final Currency currency,
+                                          @Nullable final String paymentExternalKey,
+                                          @Nullable final String paymentTransactionExternalKey,
+                                          @Nullable final TransactionStatus transactionStatus,
+                                          @Nullable final List<String> paymentControlPluginNames) {
+        if (log.isInfoEnabled()) {
+            final StringBuilder logLine = new StringBuilder(prefixMsg);
+            logLine.append("PaymentApi: transactionType='")
+                   .append(transactionType)
+                   .append("', accountId='")
+                   .append(account.getId())
+                   .append("'");
+            if (paymentMethodId != null) {
+                logLine.append(", paymentMethodId='")
+                       .append(paymentMethodId)
+                       .append("'");
+            }
+            if (paymentExternalKey != null) {
+                logLine.append(", paymentExternalKey='")
+                       .append(paymentExternalKey)
+                       .append("'");
+            }
+            if (paymentTransactionExternalKey != null) {
+                logLine.append(", paymentTransactionExternalKey='")
+                       .append(paymentTransactionExternalKey)
+                       .append("'");
+            }
+            if (paymentId != null) {
+                logLine.append(", paymentId='")
+                       .append(paymentId)
+                       .append("'");
+            }
+            if (transactionId != null) {
+                logLine.append(", transactionId='")
+                       .append(transactionId)
+                       .append("'");
+            }
+            if (amount != null) {
+                logLine.append(", amount='")
+                       .append(amount)
+                       .append("'");
+            }
+            if (currency != null) {
+                logLine.append(", currency='")
+                       .append(currency)
+                       .append("'");
+            }
+            if (transactionStatus != null) {
+                logLine.append(", transactionStatus='")
+                       .append(transactionStatus)
+                       .append("'");
+            }
+            if (paymentControlPluginNames != null) {
+                logLine.append(", paymentControlPluginNames='")
+                       .append(JOINER.join(paymentControlPluginNames))
+                       .append("'");
+            }
+            log.info(logLine.toString());
+        }
+    }
+}
diff --git a/payment/src/test/java/org/killbill/billing/payment/TestPaymentHelper.java b/payment/src/test/java/org/killbill/billing/payment/TestPaymentHelper.java
index 0c47d84..772235b 100644
--- a/payment/src/test/java/org/killbill/billing/payment/TestPaymentHelper.java
+++ b/payment/src/test/java/org/killbill/billing/payment/TestPaymentHelper.java
@@ -122,7 +122,8 @@ public class TestPaymentHelper {
 
         final InvoiceCreationInternalEvent event = new MockInvoiceCreationEvent(invoice.getId(), invoice.getAccountId(),
                                                                                 invoice.getBalance(), invoice.getCurrency(),
-                                                                                invoice.getInvoiceDate(), 1L, 2L, null);
+                                                                                invoice.getInvoiceDate(), internalCallContext.getAccountRecordId(),
+                                                                                internalCallContext.getTenantRecordId(), null);
 
         eventBus.post(event);
         return invoice;