WSO2 API Manager 3.0 : How to add a custom synapse log handler to log API related transactions

This blog post is will guide you to create your own custom log handler and the ways of integrating the custom handler with the newly released WSO2 API Manager 3.0. Although, this feature is not a new one, there are few configuration changes needed to be done compared to the previous versions of the WSO2 API Manager(2.X) due to new config model introduced with the latest product.

Also, instead of creating a simple log handler, this post will guide you to create a log handler to capture API related transactions more thouroughly. You can follow the WSO2 official docs in order to create a simple custom log handler.

This log message handler can capture below transaction details of an API. Here, i am providing sample values as well in order to clarify the data you gonna receive.

1. API_NAME : admin — PizzaShackAPI:v1.0.0
2. HTTP_METHOD : GET
3. CONTEXT : /pizzashack/1.0.0
4. FULL_REQUEST_PATH : /pizzashack/1.0.0/menu
5. SUB_PATH : /menu
6. HTTP_RESPONSE_STATUS_CODE : 200 OK
7. RESPONSE_TIME : 1302ms
8. BACKEND_TIME : 702ms
9. SERVICE_TIME : 600ms
10. ERROR_CODE : null
11. ERROR_MESSAGE : null

You can customise the code accordingly and build the project using following command

mvn clean install

Then follow the below steps in integrating custom log handler to the WSO2 API Manager 3.0

1. Download the wso2-APIM3-logHandler-1.0-SNAPSHOT.jar from the github repo or use the customised jar built from the above command.
2. Copy Jar into <APIM_HOME>/repository/components/lib
3. Add the following configuration to <APIM_HOME>/repository/conf/deployment.toml

enabled_global_handlers= ["custom_logger"]
[synapse_handlers]
custom_logger.name= "SESynapseLogHandler"
custom_logger.class= "com.wso2.apim.log.handler.SESynapseLogHandler"

4. Add the following configurations to <APIM_HOME>/repository/conf/log4j2.properties

loggers = <Existing Loggers>, com.wso2.apim.log.handler.SESynapseLogHandler
logger.com.wso2.apim.log.handler.SESynapseLogHandler.name=com.wso2.apim.log.handler.SESynapseLogHandler
logger.com.wso2.apim.log.handler.SESynapseLogHandler.level=DEBUG
logger.com.wso2.apim.log.handler.SESynapseLogHandler.appenderRef.CARBON_LOGFILE.ref=CARBON_LOGFILE

Here, note that <Existing Loggers> are the current loggers defined in the log4j2.properties file. You need to add the “com.wso2.apim.log.handler.SESynapseLogHandler” after those defined existing loggers.

5. Start the server.

6. [Optional] Check the following configurations is in the <APIM_HOME>/repository/conf/synapse-handlers.xml file.

<handlers>
	<handler name ="SESynapseLogHandler" class="com.wso2.apim.log.handler.SESynapseLogHandler"/>
</handlers>

This is only to verify whether the configurations we applied earlier in the deployment.toml is applied properly for the relevant file.

7. Deploy the Sample API from the Publisher.

8. Invoke the Sample API from the Devportal.

You will be able to see the following kind of logs in the wso2carbon.logs.

[2020–01–09 14:03:38,425] DEBUG — SESynapseLogHandler Entering SESynapseLogHandler.handleRequestInFlow
[2020–01–09 14:03:38,536] INFO — SESynapseLogHandler >> GET /pizzashack/1.0.0/menu
[2020–01–09 14:03:38,538] INFO — SESynapseLogHandler >> HTTP Headers{accept=application/json, Authorization=Bearer eyJ0eXAiOiJKV1QiLCJhbGciOiJSUzI1NiIsIng1dCI6IlpqUm1ZVE13TlRKak9XVTVNbUl6TWpnek5ESTNZMkl5TW1JeVkyRXpNamRoWmpWaU1qYzBaZz09In0.eyJhdWQiOiJodHRwOlwvXC9vcmcud3NvMi5hcGltZ3RcL2dhdGV3YXkiLCJzdWIiOiJhZG1pbkBjYXJib24uc3VwZXIiLCJhcHBsaWNhdGlvbiI6eyJvd25lciI6ImFkbWluIiwidGllciI6IlVubGltaXRlZCIsIm5hbWUiOiJEZWZhdWx0QXBwbGljYXRpb24iLCJpZCI6MSwidXVpZCI6bnVsbH0sInNjb3BlIjoiYW1fYXBwbGljYXRpb25fc2NvcGUgZGVmYXVsdCIsImlzcyI6Imh0dHBzOlwvXC9sb2NhbGhvc3Q6OTQ0M1wvb2F1dGgyXC90b2tlbiIsInRpZXJJbmZvIjp7IlVubGltaXRlZCI6eyJzdG9wT25RdW90YVJlYWNoIjp0cnVlLCJzcGlrZUFycmVzdExpbWl0IjowLCJzcGlrZUFycmVzdFVuaXQiOm51bGx9fSwia2V5dHlwZSI6IlBST0RVQ1RJT04iLCJzdWJzY3JpYmVkQVBJcyI6W3sic3Vic2NyaWJlclRlbmFudERvbWFpbiI6ImNhcmJvbi5zdXBlciIsIm5hbWUiOiJQaXp6YVNoYWNrQVBJIiwiY29udGV4dCI6IlwvcGl6emFzaGFja1wvMS4wLjAiLCJwdWJsaXNoZXIiOiJhZG1pbiIsInZlcnNpb24iOiIxLjAuMCIsInN1YnNjcmlwdGlvblRpZXIiOiJVbmxpbWl0ZWQifV0sImNvbnN1bWVyS2V5IjoibVNDY0I2UndnZVFjZGZQUjRnbWl5a1Z3QTVBYSIsImV4cCI6MTU3ODU2MTQ2NywiaWF0IjoxNTc4NTU3ODY3LCJqdGkiOiI0NTNkNTk1MS1kZmJhLTQzOTYtYjhiZC0yNWM4YTM0ZWFjY2YifQ.FeqzJuJBU28T1Rk6YKnT4rWXCdUAHhvnan7txIUCFN4Dth8XR240Vi5UsCfJMxt8gfJRgUwLq0aAhBPeb1WGin7m1KsDIKtsvBgpx39ouuVOkK9ZdAIyZYlEwmGpBy55LNLmALW4jMmcxrkyPowoz3ETH60nvgGBxjzjlEvq-1qFxwiM78SKRGzI8jSdPTPnKloSUAMwmGpGEf3WrKo9vaP71hak98mErIuQUQtFUUz1ewme8rIDgqXetSqATovKCfZjZSOY0I6XXTrU7A7sJb5pxnDO0X9zzODkLECg0yQVHoXmYks7p5mcSDtkUYouLYxUrChMLzeK26FTEdg4wQ, Host=10.100.7.106:8243, User-Agent=curl/7.64.1, X-SE-IFW-RequestId=c543f979-d8ce-4fc2–8773–04a86fc3d20b}
[2020–01–09 14:03:38,539] DEBUG — SESynapseLogHandler Returning SESynapseLogHandler.handleRequestInFlow
[2020–01–09 14:03:38,981] INFO — DependencyTracker Local entry : gov:/apimgt/statistics/ga-config.xml was added to the Synapse configuration successfully
[2020–01–09 14:03:38,998] DEBUG — SESynapseLogHandler Entering SESynapseLogHandler.handleRequestOutFlow
[2020–01–09 14:03:38,998] INFO — SESynapseLogHandler >>>> HTTP Headers {accept=application/json, Host=10.100.7.106:8243, User-Agent=curl/7.64.1, X-SE-IFW-RequestId=c543f979-d8ce-4fc2–8773–04a86fc3d20b}
[2020–01–09 14:03:38,998] DEBUG — SESynapseLogHandler Returning SESynapseLogHandler.handleRequestOutFlow
[2020–01–09 14:03:39,006] INFO — TimeoutHandler This engine will expire all callbacks after GLOBAL_TIMEOUT: 120 seconds, irrespective of the timeout action, after the specified or optional timeout
[2020–01–09 14:03:39,700] DEBUG — SESynapseLogHandler Entering SESynapseLogHandler.handleResponseInFlow
[2020–01–09 14:03:39,724] INFO — SESynapseLogHandler <<<< 200 OK
[2020–01–09 14:03:39,725] INFO — SESynapseLogHandler <<<< HTTP Headers {Content-Type=application/json, Date=Thu, 09 Jan 2020 08:33:39 GMT, Server=WSO2 Carbon Server, Transfer-Encoding=chunked}
[2020–01–09 14:03:39,725] DEBUG — SESynapseLogHandler Returning SESynapseLogHandler.handleResponseInFlow
[2020–01–09 14:03:39,728] DEBUG — SESynapseLogHandler Entering SESynapseLogHandler.handleResponseOutFlow
[2020–01–09 14:03:39,728] INFO — SESynapseLogHandler << 200 OK
[2020–01–09 14:03:39,728] INFO — SESynapseLogHandler << HTTP Headers {Access-Control-Allow-Headers=authorization,Access-Control-Allow-Origin,Content-Type,SOAPAction,Authorization, Access-Control-Allow-Methods=GET, Access-Control-Allow-Origin=*, Access-Control-Expose-Headers=, Content-Type=application/json, Date=Thu, 09 Jan 2020 08:33:39 GMT, Server=WSO2 Carbon Server, Transfer-Encoding=chunked}
[2020–01–09 14:03:39,729] DEBUG — SESynapseLogHandler Returning SESynapseLogHandler.handleResponseOutFlow
[2020–01–09 14:03:39,729] INFO — SESynapseLogHandler API Transaction Details:API_NAME: admin — PizzaShackAPI:v1.0.0,HTTP_METHOD: null, CONTEXT: /pizzashack/1.0.0,FULL_REQUEST_PATH/pizzashack/1.0.0/menu,SUB_PATH: /menu, HTTP_RESPONSE_STATUS_CODE: 200 OK, RESPONSE_TIME: 1302, BACKEND_TIME: 702, SERVICE_TIME: 600, ERROR_CODE: null, ERROR_MESSAGE: null

Hope you have gain some insight into logging API transaction details in WSO2 API Manager 3.0.