PROX-39: added logs (#2)

* PROX-39: added logs

* PROX-39: more logs

src/main/java/com/rbkmoney/proxy/test/controller/TestController.java

@@ -29,6 +29,8 @@ public class TestController {
     @RequestMapping(value = "term_url", method = RequestMethod.POST)
     public String receiveIncomingParameters(HttpServletRequest request, HttpServletResponse servletResponse) throws IOException {
 
+        LOGGER.info("Input params: {}", request.getParameterMap());
+
         String tag = "";
         ByteBuffer callback = null;
         String resp = "";

src/main/java/com/rbkmoney/proxy/test/handler/TestServerHandler.java

@@ -92,11 +92,11 @@ public class TestServerHandler implements ProviderProxySrv.Iface {
         com.rbkmoney.damsel.proxy.Intent intent = ProxyWrapper.makeFinishIntentOk();
 
         try {
-            LOGGER.info("Call CDS in processPayment. Token {}, session: {}", token, session);
+            LOGGER.info("Processed: call CDS. Token {}, session: {}", token, session);
             cardData = cds.getSessionCardData(token, session);
         } catch (TException e) {
-            LOGGER.error("CDS Exception in processPayment", e);
+            LOGGER.error("Processed: CDS Exception", e);
-            return ProxyProviderWrapper.makeProxyResultFailure("CDS Exception in processPayment", e.getMessage());
+            return ProxyProviderWrapper.makeProxyResultFailure("Processed: CDS Exception", e.getMessage());
         }
 
         CardUtils cardUtils = new CardUtils(cardList);
@@ -106,7 +106,7 @@ public class TestServerHandler implements ProviderProxySrv.Iface {
             TestMpiAction action = TestMpiAction.findByValue(card.get().getAction());
 
             if (!cardUtils.isEnrolled(card)) {
-                String error = null;
+                String error;
                 switch (action) {
                     case INCUFFICIENT_FUNDS:
                         error = INCUFFICIENT_FUNDS.getAction();
@@ -125,26 +125,29 @@ public class TestServerHandler implements ProviderProxySrv.Iface {
                                 TestMpiUtils.generateInvoice(context.getPayment()),
                                 Collections.emptyMap()
                         );
-                        return ProxyProviderWrapper.makeProxyResult(
+                        ProxyResult proxyResult = ProxyProviderWrapper.makeProxyResult(
                                 intent,
                                 "captured".getBytes(),
                                 transactionInfo
                         );
+                        LOGGER.info("Processed: success {}", proxyResult);
+                        return proxyResult;
                     default:
                         error = UNKNOWN_FAILURE.getAction();
 
                 }
-                return ProxyProviderWrapper.makeProxyResultFailure(
+                ProxyResult proxyResult = ProxyProviderWrapper.makeProxyResultFailure(error, error);
-                        error,
+                LOGGER.info("Processed: failure {}", proxyResult);
-                        error
+                return ProxyProviderWrapper.makeProxyResultFailure(error, error);
-                );
             }
 
         } else {
-            return ProxyProviderWrapper.makeProxyResultFailure(
+            ProxyResult proxyResult = ProxyProviderWrapper.makeProxyResultFailure(
                     UNSUPPORTED_CARD.getAction(),
                     UNSUPPORTED_CARD.getAction()
             );
+            LOGGER.info("Processed: failure {}", proxyResult);
+            return proxyResult;
         }
 
         VerifyEnrollmentResponse verifyEnrollmentResponse = null;
@@ -155,7 +158,7 @@ public class TestServerHandler implements ProviderProxySrv.Iface {
                     cardData.getExpDate().getMonth()
             );
         } catch (IOException e) {
-            LOGGER.error("Exception in verifyEnrollment", e);
+            LOGGER.error("Processed: Exception in verifyEnrollment", e);
             return ProxyProviderWrapper.makeProxyResultFailure(
                     UNKNOWN_FAILURE.getAction(),
                     UNKNOWN_FAILURE.getAction()
@@ -163,16 +166,17 @@ public class TestServerHandler implements ProviderProxySrv.Iface {
         }
 
         if (verifyEnrollmentResponse.getEnrolled().equals(TestMpiEnrollmentStatus.AUTHENTICATION_AVAILABLE)) {
-
             String tag = "MPI-" + TestMpiUtils.generateInvoice(context.getPayment());
+            LOGGER.info("Processed: suspend tag {}", tag);
 
-            // Prepare response
             String url = verifyEnrollmentResponse.getAcsUrl();
             Map<String, String> params = new HashMap<>();
             params.put("PaReq", verifyEnrollmentResponse.getPaReq());
             params.put("MD", tag);
             params.put("TermUrl", TestMpiUtils.getCallbackUrl(callbackUrl, "/test/term_url{?termination_uri}"));
 
+            LOGGER.info("Processed: prepare redirect params {}", params);
+
             intent = ProxyWrapper.makeIntentWithSuspendIntent(
                     tag, BaseWrapper.makeTimerTimeout(timerTimeout),
                     UserInteractionWrapper.makeUserInteraction(
@@ -187,22 +191,24 @@ public class TestServerHandler implements ProviderProxySrv.Iface {
         Map<String, String> extra = new HashMap<>();
         extra.put(TestMpiUtils.PA_REQ, verifyEnrollmentResponse.getPaReq());
 
-        LOGGER.info("Extra map {}", extra);
+        LOGGER.info("Processed: Extra map {}", extra);
 
         byte[] state;
         try {
             state = Converter.mapToByteArray(extra);
         } catch (IOException e) {
 
-            LOGGER.error("Converter Exception in processPayment", e);
+            LOGGER.error("Processed: Converter Exception", e);
             return ProxyProviderWrapper.makeProxyResultFailure("Converter", e.getMessage());
         }
 
-        return ProxyProviderWrapper.makeProxyResult(intent, state, transactionInfo);
+        ProxyResult proxyResult = ProxyProviderWrapper.makeProxyResult(intent, state, transactionInfo);
+        LOGGER.info("Processed: finish {}", proxyResult);
+        return proxyResult;
     }
 
     private ProxyResult captured(Context context) {
-        LOGGER.info("captured start");
+        LOGGER.info("Captured: start");
         com.rbkmoney.damsel.proxy_provider.InvoicePayment payment = context.getPayment().getPayment();
         TransactionInfo transactionInfoContractor = payment.getTrx();
         TransactionInfo transactionInfo = DomainWrapper.makeTransactionInfo(
@@ -213,47 +219,51 @@ public class TestServerHandler implements ProviderProxySrv.Iface {
         context.getSession().setState("confirm".getBytes());
 
         Intent intent = ProxyWrapper.makeFinishIntentOk();
-        LOGGER.info("capturePayment finish");
+        ProxyResult proxyResult = ProxyProviderWrapper.makeProxyResult(intent, "confirm".getBytes(), transactionInfo);
-        return ProxyProviderWrapper.makeProxyResult(intent, "confirm".getBytes(), transactionInfo);
+
+        LOGGER.info("Captured: proxyResult {}", proxyResult);
+        return proxyResult;
     }
 
     private ProxyResult cancelled(Context context) {
-        return ProxyProviderWrapper.makeProxyResultFailure("Unsupported method CANCEL", "Unsupported method CANCEL");
+        ProxyResult proxyResult = ProxyProviderWrapper.makeProxyResultFailure("Unsupported method CANCEL", "Unsupported method CANCEL");
+        LOGGER.error("Cancelled: proxyResult {}", proxyResult);
+        return proxyResult;
     }
 
     @Override
     public CallbackResult handlePaymentCallback(ByteBuffer byteBuffer, Context context) throws TryLater, TException {
-        LOGGER.info("handlePaymentCallback start");
+        LOGGER.info("HandlePaymentCallback: start");
         InvoicePayment invoicePayment = context.getPayment().getPayment();
+        String token = invoicePayment.getPayer().getPaymentTool().getBankCard().getToken();
+        String session = invoicePayment.getPayer().getSession();
         options = context.getOptions();
 
         HashMap<String, String> parameters;
 
-        // Merge parameters
+        LOGGER.info("HandlePaymentCallback: merge input parameters");
         try {
             parameters = (HashMap<String, String>) Converter.byteArrayToMap(context.getSession().getState());
             parameters.putAll(Converter.byteBufferToMap(byteBuffer));
         } catch (Exception e) {
-            LOGGER.error("Parse ByteBuffer Exception in handlePaymentCallback", e);
+            LOGGER.error("HandlePaymentCallback: Parse ByteBuffer Exception", e);
             return ProxyProviderWrapper.makeCallbackResultFailure(
                     "error".getBytes(),
-                    "Parse ByteBuffer Exception in handlePaymentCallback",
+                    "HandlePaymentCallback: Parse ByteBuffer Exception",
                     e.getMessage()
             );
         }
+        LOGGER.info("HandlePaymentCallback: merge input parameters {}", parameters);
 
         CardData cardData;
         try {
-            LOGGER.info("CDS: handlePaymentCallback get Card Data");
+            LOGGER.info("HandlePaymentCallback: call CDS. Token {}, session: {}", token, session);
-            cardData = cds.getSessionCardData(
+            cardData = cds.getSessionCardData(token, session);
-                    invoicePayment.getPayer().getPaymentTool().getBankCard().getToken(),
-                    invoicePayment.getPayer().getSession()
-            );
         } catch (TException e) {
-            LOGGER.error("CDS Exception in handlePaymentCallback", e);
+            LOGGER.error("HandlePaymentCallback: CDS Exception", e);
             return ProxyProviderWrapper.makeCallbackResultFailure(
                     "error".getBytes(),
-                    "CDS Exception in handlePaymentCallback",
+                    "HandlePaymentCallback: CDS Exception",
                     e.getMessage()
             );
         }
@@ -262,15 +272,14 @@ public class TestServerHandler implements ProviderProxySrv.Iface {
         try {
             validatePaResResponse = testMpiApi.validatePaRes(cardData.getPan(), parameters.get("paRes"));
         } catch (IOException e) {
-            LOGGER.error("Exception in handlePaymentCallback", e);
+            LOGGER.error("HandlePaymentCallback: Exception", e);
             return ProxyProviderWrapper.makeCallbackResultFailure(
                     "error".getBytes(),
-                    "Exception in handlePaymentCallback",
+                    "HandlePaymentCallback: Exception",
                     e.getMessage()
             );
         }
-
+        LOGGER.info("HandlePaymentCallback: validatePaResResponse {}", validatePaResResponse);
-        LOGGER.info("validatePaResResponse {}", validatePaResResponse);
 
         if (validatePaResResponse.getTransactionStatus().equals(TestMpiTransactionStatus.AUTHENTICATION_SUCCESSFUL)) {
             byte[] callbackResponse = new byte[0];
@@ -281,20 +290,17 @@ public class TestServerHandler implements ProviderProxySrv.Iface {
                     Collections.emptyMap()
             );
 
-            return ProxyProviderWrapper.makeCallbackResult(
+            ProxyResult proxyResult = ProxyProviderWrapper.makeProxyResult(
-                    callbackResponse,
+                    intent, "captured".getBytes(), transactionInfo
-                    ProxyProviderWrapper.makeProxyResult(
-                            intent, "captured".getBytes(), transactionInfo
-                    )
             );
+
+            LOGGER.info("HandlePaymentCallback: callbackResponse {}, proxyResult {}", callbackResponse, proxyResult);
+            return ProxyProviderWrapper.makeCallbackResult(callbackResponse, proxyResult);
         }
 
         CardUtils cardUtils = new CardUtils(cardList);
         Optional<Card> card = cardUtils.getCardByPan(cardData.getPan());
-
-
         TestMpiAction action = TestMpiAction.findByValue(card.get().getAction());
-
         String error;
 
         switch (action) {
@@ -309,12 +315,12 @@ public class TestServerHandler implements ProviderProxySrv.Iface {
 
         }
 
-        LOGGER.info("handlePaymentCallback finish");
+        CallbackResult callbackResult = ProxyProviderWrapper.makeCallbackResultFailure(
-        return ProxyProviderWrapper.makeCallbackResultFailure(
+                "error".getBytes(), "HandlePaymentCallback: error", error
-                "error".getBytes(),
-                "Exception in handlePaymentCallback",
-                error
         );
+
+        LOGGER.info("HandlePaymentCallback: callbackResult {}", callbackResult);
+        return callbackResult;
     }
 
 }

src/main/java/com/rbkmoney/proxy/test/utils/testmpi/TestMpiApi.java

@@ -25,24 +25,31 @@ public class TestMpiApi {
     private String url;
 
     public VerifyEnrollmentResponse verifyEnrollment(String pan, short year, byte month) throws IOException {
+        LOGGER.info("VerifyEnrollment input params: pan {}, year {}, month {}",
+                TestMpiUtils.maskNumber(pan), year, month
+        );
+
         MultiValueMap<String, Object> map = new LinkedMultiValueMap<String, Object>();
         map.add("pan", pan);
         map.add("year", String.valueOf(year));
         map.add("month", String.valueOf(month));
 
-        VerifyEnrollmentResponse result;
+        VerifyEnrollmentResponse response = restTemplate.postForObject(prepareUrl("verifyEnrollment"), map, VerifyEnrollmentResponse.class);
-        result = restTemplate.postForObject(prepareUrl("verifyEnrollment"), map, VerifyEnrollmentResponse.class);
+
-        return result;
+        LOGGER.info("VerifyEnrollment response {}", response);
+        return response;
     }
 
     public ValidatePaResResponse validatePaRes(String pan, String paRes) throws IOException {
+        LOGGER.info("ValidatePaRes input params: pan {}, paRes {}", TestMpiUtils.maskNumber(pan), paRes);
+
         MultiValueMap<String, Object> map = new LinkedMultiValueMap<String, Object>();
         map.add("pan", pan);
-        map.add("paRes", String.valueOf(paRes));
+        map.add("paRes", paRes);
 
-        ValidatePaResResponse result;
+        ValidatePaResResponse response = restTemplate.postForObject(prepareUrl("validatePaRes"), map, ValidatePaResResponse.class);
-        result = restTemplate.postForObject(prepareUrl("validatePaRes"), map, ValidatePaResResponse.class);
+        LOGGER.info("ValidatePaRes response {}", response);
-        return result;
+        return response;
     }
 
     private String prepareUrl(String path) throws IOException {

src/main/java/com/rbkmoney/proxy/test/utils/testmpi/TestMpiUtils.java

@@ -1,6 +1,7 @@
 package com.rbkmoney.proxy.test.utils.testmpi;
 
 import com.rbkmoney.damsel.proxy_provider.PaymentInfo;
+import net.logstash.logback.encoder.org.apache.commons.lang.StringUtils;
 import org.apache.http.client.utils.URIBuilder;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
@@ -12,6 +13,8 @@ public class TestMpiUtils {
 
     private final static Logger LOGGER = LoggerFactory.getLogger(TestMpiUtils.class);
 
+    public final static String MASK_CHAR = "*";
+
     public final static String MESSAGE_ID = "messageId";
     public final static String PA_REQ = "PaReq";
     public final static String PA_RES = "PaRes";
@@ -36,4 +39,18 @@ public class TestMpiUtils {
     public static String generateInvoice(PaymentInfo payment) {
         return payment.getInvoice().getId() + payment.getPayment().getId();
     }
+
+    public static String maskNumber(final String creditCardNumber, int startLength, int endLength, String maskChar) {
+        final String cardNumber = creditCardNumber.replaceAll("\\D", "");
+
+        final int start = startLength;
+        final int end = cardNumber.length() - endLength;
+        final String overlay = StringUtils.repeat(maskChar, end - start);
+
+        return StringUtils.overlay(cardNumber, overlay, start, end);
+    }
+
+    public static String maskNumber(final String creditCardNumber) {
+        return maskNumber(creditCardNumber, 4, 4, MASK_CHAR);
+    }
 }