[WSO2] [APIM] [Gateway] How to log the Total Request Execution Time for a API Gateway Request

Latency is a major problem we face when working with APIs. When integrating an existing backend with an API manager, we specially concern about latency related issues. There are multiple reason that can cause latency issues; i.e network delays, preprocessing or post processing mediations logics, backend overload etc. In WSO2 API Manager, we can use a custom logger to log the APIM execution latency related information.

Please not that the the component I used in this article is written by Vanjikumaran [1,2]. Following are the steps to configure it with WSO2 API Gateway.

1. Login to the publisher, create and publish a duplicate api which calls the same backend which is being called by the original API we want to investigate.
2. Clone the custom handler from here and build it using maven.
3. Copy org.wso2.carbon.custom.logging-1.0.0.jar in the target directory, into <APIM_HOME>/repository/components/lib directory.
4. Go to <APIM_HOME>/repository/deployment/server/synapse-configs/default/api/ directory and open the XML file which belongs to the new API.
5. Locate handlers section and add following two handles to top and bottom of the handlers list respectively.

<handler class="org.wso2.carbon.custom.logging.CustomInboundLogging"/>
<handler class="org.wso2.carbon.custom.logging.CustomOutboundLogging"/>

Sample:

   <handlers>
      <handler class="org.wso2.carbon.custom.logging.CustomInboundLogging"/>
      <handler class="org.wso2.carbon.apimgt.gateway.handlers.common.APIMgtLatencyStatsHandler"/>
      <handler class="org.wso2.carbon.apimgt.gateway.handlers.security.CORSRequestHandler">
         <property name="apiImplementationType" value="ENDPOINT"/>
      </handler>
      <handler class="org.wso2.carbon.apimgt.gateway.handlers.security.APIAuthenticationHandler"/>
      <handler class="org.wso2.carbon.apimgt.gateway.handlers.throttling.ThrottleHandler"/>
      <handler class="org.wso2.carbon.apimgt.gateway.handlers.analytics.APIMgtUsageHandler"/>
      <handler class="org.wso2.carbon.apimgt.gateway.handlers.analytics.APIMgtGoogleAnalyticsTrackingHandler">
         <property name="configKey" value="gov:/apimgt/statistics/ga-config.xml"/>
      </handler>
      <handler class="org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler"/>
      <handler class="org.wso2.carbon.custom.logging.CustomOutboundLogging"/>
   </handlers>

6. Restart the server and invoke the API.
7. You will see a log similar to following with the latency information.

[2017-11-15 18:20:59,712] INFO - CustomInboundLogging Inbound API call from client to gateway: correlationID=b9bcb61c-236a-47b6-910d-b2ced692b82f , httpMethod=GET , transactionId=7758369265731758509094 , userAgent=curl/7.54.0 , requestURI=/pizzashack/1.0.0/menu , requestTime=Wed Nov 15 18:20:59 PST 2017 , clientIP=10.10.20.19
[2017-11-15 18:20:59,729] INFO - CustomOutboundLogging Outbound API call from gateway to client: correlationID=b9bcb61c-236a-47b6-910d-b2ced692b82f , httpMethod=GET , appName=DefaultApplication , applicationId=1 , apiName=PizzaShackAPI , apiPublisher=admin , apiConsumerKey=S6efziZ11z4feJE9HaGSFSZxA80a , userName=admin@carbon.super , transactionId=7758369265731758509094 , requestURI=/pizzashack/1.0.0/menu , statusCode=200 , throttlingLatency=1 , roundTripLatency=17 , gatewayLatency=3 , keyManagerLatency=2 , EndPointURL=https://localhost:9443/am/sample/pizzashack/v1/api/

Please note that this approach is only used for dev requirements and not recommended for production as it adds an extra effort to each API call.

[1] https://plus.google.com/+VanjikumaranSivajothy
[2] https://github.com/vanjikumaran/APIMlogginghandlers