killbill-memoizeit

Cleans up logging of exceptions.

5/4/2016 8:51:57 PM

Details

diff --git a/payment/src/main/java/org/killbill/billing/payment/core/sm/control/OperationControlCallback.java b/payment/src/main/java/org/killbill/billing/payment/core/sm/control/OperationControlCallback.java
index 9e09c24..8c64a2d 100644
--- a/payment/src/main/java/org/killbill/billing/payment/core/sm/control/OperationControlCallback.java
+++ b/payment/src/main/java/org/killbill/billing/payment/core/sm/control/OperationControlCallback.java
@@ -156,7 +156,7 @@ public abstract class OperationControlCallback extends OperationCallbackBase<Pay
         if (e.getCause() instanceof OperationException) {
             return (OperationException) e.getCause();
         }
-        logger.warn("Operation failed for accountId='{}'", paymentStateContext.getAccount().getId(), e);
+        logger.warn("Operation failed for accountId='{}' accountExternalKey='{}' error='{}'", paymentStateContext.getAccount().getExternalKey(), e.getMessage());
         return new OperationException(e, getOperationResultOnException(paymentStateContext));
     }
 
diff --git a/payment/src/main/java/org/killbill/billing/payment/core/sm/OperationCallbackBase.java b/payment/src/main/java/org/killbill/billing/payment/core/sm/OperationCallbackBase.java
index 50c95a3..7eb4821 100644
--- a/payment/src/main/java/org/killbill/billing/payment/core/sm/OperationCallbackBase.java
+++ b/payment/src/main/java/org/killbill/billing/payment/core/sm/OperationCallbackBase.java
@@ -67,9 +67,7 @@ public abstract class OperationCallbackBase<CallbackOperationResult, CallbackOpe
                                                                                                                                            account.getExternalKey(),
                                                                                                                                            paymentConfig,
                                                                                                                                            callback);
-            logger.debug("Calling plugin(s) {}", pluginNames);
             final OperationResult operationResult = PaymentPluginDispatcher.dispatchWithExceptionHandling(account, pluginNames, task, paymentPluginDispatcher);
-            logger.debug("Successful plugin(s) call of {} for account {} with result {}", pluginNames, account.getExternalKey(), operationResult);
             return operationResult;
         } catch (final PaymentApiException e) {
             throw unwrapExceptionFromDispatchedTask(e);
diff --git a/payment/src/main/java/org/killbill/billing/payment/core/sm/payments/PaymentOperation.java b/payment/src/main/java/org/killbill/billing/payment/core/sm/payments/PaymentOperation.java
index 83d663e..c8db8e8 100644
--- a/payment/src/main/java/org/killbill/billing/payment/core/sm/payments/PaymentOperation.java
+++ b/payment/src/main/java/org/killbill/billing/payment/core/sm/payments/PaymentOperation.java
@@ -90,7 +90,6 @@ public abstract class PaymentOperation extends OperationCallbackBase<PaymentTran
 
     @Override
     protected OperationException unwrapExceptionFromDispatchedTask(final PaymentApiException e) {
-        logger.warn("Payment plugin call threw an exception for accountExternalKey='{}'", paymentStateContext.getAccount().getExternalKey(), e);
         return convertToUnknownTransactionStatusAndErroredPaymentState(e);
     }
 
diff --git a/payment/src/main/java/org/killbill/billing/payment/dispatcher/PaymentPluginDispatcher.java b/payment/src/main/java/org/killbill/billing/payment/dispatcher/PaymentPluginDispatcher.java
index 7a4e1e2..a84a036 100644
--- a/payment/src/main/java/org/killbill/billing/payment/dispatcher/PaymentPluginDispatcher.java
+++ b/payment/src/main/java/org/killbill/billing/payment/dispatcher/PaymentPluginDispatcher.java
@@ -45,15 +45,15 @@ public class PaymentPluginDispatcher {
         try {
             log.debug("Calling plugin(s) {}", pluginNames);
             final ReturnType result = pluginDispatcher.dispatchWithTimeout(callable);
-            log.debug("Successful plugin(s) call of {} for account {} with result {}", pluginNames, accountId, result);
+            log.debug("Successful plugin(s) call of {} for account {} with result {}", pluginNames, accountExternalKey, result);
             return result;
         } catch (final TimeoutException e) {
-            final String errorMessage = String.format("TimeoutException while executing plugin='%s'", pluginNames);
+            final String errorMessage = String.format("Call TIMEOUT for accountId='%s' accountExternalKey='%s' plugin='%s'", accountId, accountExternalKey, pluginNames);
             log.warn(errorMessage);
             throw new PaymentApiException(ErrorCode.PAYMENT_PLUGIN_TIMEOUT, accountId, errorMessage);
         } catch (final InterruptedException e) {
             Thread.currentThread().interrupt();
-            final String errorMessage = String.format("InterruptedException while executing plugin='%s'", pluginNames);
+            final String errorMessage = String.format("Call was interrupted for accountId='%s' accountExternalKey='%s' plugin='%s'", accountId, accountExternalKey, pluginNames);
             log.warn(errorMessage, e);
             throw new PaymentApiException(ErrorCode.PAYMENT_INTERNAL_ERROR, MoreObjects.firstNonNull(e.getMessage(), errorMessage));
         } catch (final ExecutionException e) {
diff --git a/payment/src/test/java/org/killbill/billing/payment/api/TestPaymentApi.java b/payment/src/test/java/org/killbill/billing/payment/api/TestPaymentApi.java
index bb8c247..c64ef5f 100644
--- a/payment/src/test/java/org/killbill/billing/payment/api/TestPaymentApi.java
+++ b/payment/src/test/java/org/killbill/billing/payment/api/TestPaymentApi.java
@@ -23,13 +23,11 @@ import java.util.ArrayList;
 import java.util.HashMap;
 import java.util.List;
 import java.util.UUID;
-import java.util.concurrent.Callable;
 import java.util.concurrent.TimeoutException;
 
 import javax.annotation.Nullable;
 
 import org.joda.time.LocalDate;
-import org.killbill.automaton.OperationException;
 import org.killbill.billing.ErrorCode;
 import org.killbill.billing.account.api.Account;
 import org.killbill.billing.catalog.api.Currency;
@@ -39,11 +37,9 @@ import org.killbill.billing.invoice.api.InvoiceApiException;
 import org.killbill.billing.invoice.api.InvoiceItem;
 import org.killbill.billing.payment.MockRecurringInvoiceItem;
 import org.killbill.billing.payment.PaymentTestSuiteWithEmbeddedDB;
-import org.killbill.billing.payment.core.sm.OperationCallbackBase;
 import org.killbill.billing.payment.dao.PaymentAttemptModelDao;
 import org.killbill.billing.payment.dao.PaymentSqlDao;
 import org.killbill.billing.payment.invoice.InvoicePaymentControlPluginApi;
-import org.killbill.billing.payment.logging.SpyLogger;
 import org.killbill.billing.payment.plugin.api.PaymentPluginStatus;
 import org.killbill.billing.payment.provider.ExternalPaymentProviderPlugin;
 import org.killbill.billing.payment.provider.MockPaymentProviderPlugin;
@@ -54,15 +50,14 @@ import org.testng.annotations.BeforeClass;
 import org.testng.annotations.BeforeMethod;
 import org.testng.annotations.Test;
 
-import com.google.common.base.Optional;
 import com.google.common.collect.ImmutableList;
 
-import static org.killbill.billing.payment.logging.TestLoggingHelper.withSpyLogger;
 import static org.testng.Assert.assertEquals;
 import static org.testng.Assert.assertFalse;
 import static org.testng.Assert.assertNotNull;
 import static org.testng.Assert.assertNull;
 import static org.testng.Assert.assertTrue;
+import static org.testng.Assert.fail;
 
 public class TestPaymentApi extends PaymentTestSuiteWithEmbeddedDB {
 
@@ -1183,38 +1178,16 @@ public class TestPaymentApi extends PaymentTestSuiteWithEmbeddedDB {
         final String paymentExternalKey = "ohhhh";
         final String transactionExternalKey = "naaahhh";
 
-        final String pluginName = mockPaymentProviderPlugin.PLUGIN_NAME;
-
         mockPaymentProviderPlugin.makePluginWaitSomeMilliseconds((int) (paymentConfig.getPaymentPluginTimeout().getMillis() + 100));
-
-        SpyLogger spyLogger = withSpyLogger(OperationCallbackBase.class, new Callable<Void>() {
-
-            @Override
-            public Void call() throws Exception {
-                PaymentApiException thrownException = null;
-
-                try {
-                    final Payment payment = paymentApi.createPurchase(account, account.getPaymentMethodId(), null, requestedAmount, Currency.AED, paymentExternalKey, transactionExternalKey,
-                                                                      ImmutableList.<PluginProperty>of(), callContext);
-                } catch (PaymentApiException e) {
-                    thrownException = e;
-                }
-
-                assertNotNull(thrownException);
-
-                Throwable timeoutException = thrownException.getCause();
-                assertNotNull(timeoutException);
-                assertTrue(timeoutException instanceof TimeoutException);
-
-                return null;
-            }
-        });
-
-        assertTrue(spyLogger.contains("Calling plugin.*" + pluginName, Optional.of(SpyLogger.LOG_LEVEL_DEBUG)));
-        assertTrue(spyLogger.contains("TimeoutException.*" + pluginName, Optional.of(SpyLogger.LOG_LEVEL_WARN)));
+        try {
+            final Payment payment = paymentApi.createPurchase(account, account.getPaymentMethodId(), null, requestedAmount, Currency.AED, paymentExternalKey, transactionExternalKey,
+                                                              ImmutableList.<PluginProperty>of(), callContext);
+            fail();
+        } catch (PaymentApiException e) {
+            assertEquals(e.getCode(), ErrorCode.PAYMENT_PLUGIN_TIMEOUT.getCode());
+        }
     }
 
-
     @Test(groups = "slow")
     public void testSanityAcrossTransactionTypes() throws PaymentApiException {