Troubleshooting Payment System

This article describes how to increase debug logging in YSoft Payment System.

Debug logging of YSoft Payment System is useful in case there is some issue with the behavior of YSoft Payment System and terminalserver.log, localhost_access_log.*.txt, payment-system.log, paypal-integration.log, or the log files from the Management Server or the Site server do not provide you with enough information root cause.

For example:

  • the transaction settlement request is replied by HTTP error code 400 without obvious reason (HTTP error code 400 means Bad Request.)

  • the transaction settlement is processed with a delay and logs of payment are not showing the exact time when the request has came (by default only information that request has been processed is logged).

  • the creation Payment Gateway plugin fails.

Resolution

In order to enable debug logging, proceed this way:

  1. Edit file <Payment System>\webapps\ROOT\WEB-INF\classes\logback.xml

    • Find the line:
      <logger name="com.ysoft" level="${payment.loglevel:-INFO}"/>
      and put following text on the new line behind it:
      <logger name="org.springframework.web" level="DEBUG"/>

  2. (Optional) Edit file <Payment System>\webapps\paypal-integration\WEB-INF\classes\logback.xml

    • Find line <root level="INFO"> and replace it by <root level="DEBUG">

  3. Wait one minute for configuration to reload

  4. Reproduce problematic situation again

  5. If the logging level is still not sufficient enough, replace all occurrences of INFO by DEBUG in the file from point 1 and repeat point 3.

How does output of debug logging look like

Default logging level

Please note the problematic transaction is highlighted in orange and is visible only in localhost_access_log.*.txt log.

  • localhost_access_log.*.txt
    127.0.0.1 - - [15/Oct/2014:08:19:11 +0200] "PUT /payment-system/api/v1/clearing/transaction/ testingTransaction1 / HTTP/1.1" 400 46

  • payment-system.log
    08:19:11.285 [http-nio-8443-exec-8] INFO  c.y.v.s.AuthenticationSuccessListener - User [safeq] authenticated successfully from IP address 127.0.0.1
    08:19:11.370 [http-nio-8443-exec-8] WARN  c.y.vault.api.AbstractApiController - Cannot settle transaction with no reservations

Debug logging level

Please note the problematic transaction is highlighted in orange and is visible in both log files. It is now easy to understand that WARN message Cannot settle transaction with no reservations is related to our highlighted transaction (as the row containing transaction ID and the row containing WARN message shares the same thread ID http-nio-8443-exec-3 ).

  • localhost_access_log.*.txt
    127.0.0.1 - - [15/Oct/2014:08:38:16 +0200] "PUT /payment-system/api/v1/clearing/ transaction/ testingTransaction1 / HTTP/1.1" 400 46

  • payment-system.log
    08:38:16.754 [http-nio-8443-exec-3] INFO  c.y.v.s.AuthenticationSuccessListener - User [safeq] authenticated successfully from IP address 127.0.0.1
    08:38:16.761 [http-nio-8443-exec-3] DEBUG o.s.web.servlet.DispatcherServlet - DispatcherServlet with name 'api' processing PUT request for [/payment-system/api/v1/clearing/transaction/ testingTransaction1 /]
    08:38:16.762 [http-nio-8443-exec-3] DEBUG o.s.w.s.m.m.a.RequestMappingHandlerMapping - Looking up handler method for path /clearing/transaction/ testingTransaction1 /
    08:38:16.763 [http-nio-8443-exec-3] DEBUG o.s.w.s.m.m.a.RequestMappingHandlerMapping - Returning handler method [public org.springframework.http.HttpEntity<?> com.ysoft.vault.api.clearing.ClearingApiController.changeState(java.lang.String,com.ysoft.vault.api.clearing.StateChangeRequest,com.ysoft.vault.security.SimpleUserDetails)]
    08:38:16.764 [http-nio-8443-exec-3] DEBUG o.s.w.s.m.m.a.RequestResponseBodyMethodProcessor - Reading [class com.ysoft.vault.api.clearing.StateChangeRequest] as "application/json;charset=UTF-8" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@1c3f115]
    08:38:16.772 [http-nio-8443-exec-3] DEBUG o.s.w.s.m.m.a.ExceptionHandlerExceptionResolver - Resolving exception from handler [public org.springframework.http.HttpEntity<?> com.ysoft.vault.api.clearing.ClearingApiController.changeState(java.lang.String,com.ysoft.vault.api.clearing.StateChangeRequest,com.ysoft.vault.security.SimpleUserDetails)]: com.ysoft.vault.exception.IllegalInputException: Cannot settle transaction with no reservations
    08:38:16.773 [http-nio-8443-exec-3] DEBUG o.s.w.s.m.m.a.ExceptionHandlerExceptionResolver - Invoking @ExceptionHandler method: public org.springframework.http.HttpEntity<java.lang.String> com.ysoft.vault.api.AbstractApiController.businessExceptionHandler(com.ysoft.vault.exception.BusinessException)
    08:38:16.773 [http-nio-8443-exec-3] WARN  c.y.vault.api.AbstractApiController - Cannot settle transaction with no reservations
    08:38:16.775 [http-nio-8443-exec-3] DEBUG o.s.w.s.m.m.a.HttpEntityMethodProcessor - Written [Cannot settle transaction with no reservations] as "text/html" using [org.springframework.http.converter.StringHttpMessageConverter@16ebae2]
    08:38:16.775 [http-nio-8443-exec-3] DEBUG o.s.web.servlet.DispatcherServlet - Null ModelAndView returned to DispatcherServlet with name 'api': assuming HandlerAdapter completed request handling
    08:38:16.775 [http-nio-8443-exec-3] DEBUG o.s.web.servlet.DispatcherServlet - Successfully completed request