com.atlassian.confluence.content.render.xhtml.migration.exceptions.UnknownMacroMigrationException: The macro 'next_previous_links' is unknown.

Working with Observability

Owned by Former user (Deleted)
Last updated: Dec 10, 2018Version comment
11 min read

Observability in WSO2 API Manager (WSO2 API-M) is really important to debug issues in a short period. WSO2 API-M facilitates observability by logging the following important points of the system with the time taken to achieve them. 

  • Method Calls
  • External Calls (HTTP/HTTPS)
  • Database Calls (JDBC and LDAP)

Furthermore, when observability is enabled in WSO2 API-M, a random correlation ID is generated within the WSO2 API-M for each transaction allowing you to correlate the latter three types of calls. Thereby, the requests and the responses that correspond to a specific API call will be logged under one correlation ID making it easier to analyze the information. If required, you can provide a unique correlation ID by adding the activityid in the header to the request sent to WSO2 API-M.

  • Observability is not enabled by default as it impacts WSO2 API Manager's performance.
  • In order to use this feature, apply the WUM update for WSO2 API-M 2.1.0 released on 2018-11-24.

If you want to deploy a WUM update in to production, you need to have a paid subscription. If you do not have a paid subscription, you can use this feature with the next version of WSO2 API Manager when it is released. For more information on updating WSO2 API Manager using WUM, see /wiki/spaces/updates/pages/16318501 in the WSO2 Updates Guide.

The following sections provide for more information on observability with regard to WSO2 API Manager.

Enabling observability on WSO2 API-M

Step 1 - Configure observability

  1. Add the Log4J configurations so that a log file is created for the purpose of observability when API Manager server is started.
    Add the following code to the <API-M_HOME>/repository/conf/log4j.properties file. 

    # correlation logs
log4j.logger.correlation=INFO, CORRELATION
log4j.additivity.correlation=false
# Appender config for correlation logs
log4j.appender.CORRELATION=org.apache.log4j.RollingFileAppender
log4j.appender.CORRELATION.File=${carbon.home}/repository/logs/${instance.log}/correlation.log
log4j.appender.CORRELATION.MaxFileSize=10MB
log4j.appender.CORRELATION.layout=org.apache.log4j.PatternLayout
log4j.appender.CORRELATION.Threshold=INFO
log4j.appender.CORRELATION.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss,SSS}|%X{Correlation-ID}|%t|%m%n

    Note that the maximum file size of the correlation log is set to 10MB by default in the above configuration, which means that when the size of the file exceeds 10MB, a new log file is created. If required, you can change this file size.

  2. Add the valve configurations for the purpose of deriving the correlation ID.
    Add the following configurations under the <Host> tag in the <API-M_HOME>/repository/conf/tomcat/catalina-server.xml file.

    <Valve className="org.wso2.carbon.tomcat.ext.valves.RequestCorrelationIdValve" headerToCorrelationIdMapping="{'activityid':'Correlation-ID'}" queryToCorrelationIdMapping="{'RelayState':'Correlation-ID'}"/>

  3. Add the Synapse Handler configurations to facilitate external call logging.
    Add the following configurations as a handler after the <handler> tag in the <API-M_HOME>/repository/conf/synapse-handlers.xml file.

    <handler name="externalCallLogger" class="org.wso2.carbon.apimgt.gateway.handlers.LogsHandler"/>

Step 2 - Enable observability

If you want correlation logs to be enabled every time the server starts, add the following system property to the product startup script (stored in the <API-M_HOME>/bin/ directory) and set it to true.


Skip this step if you want to pass the system property to enable observability at the time of starting the WSO2 API-M server.


Step 3 - Start the WSO2 API-M server

Start the WSO2 API-M server.

When observability is enabled in WSO2 API Manager, a separate log file named correlation.log is created in the <API-M_HOME>/repository/logs directory.

Types of correlation logs

The following are the types of logs that are available when working with observability in WSO2 API-M.

Method call logs

When correlation logging is enabled, the API Manager logs the time taken to execute certain important methods of the following modules.

  • org.wso2.carbon.apimgt.gateway
  • org.wso2.carbon.apimgt.keymgt
  • org.wso2.carbon.apimgt.impl

In API Manager, by default the important methods are marked with the @MethodStats annotation, and this annotation can be found at both the method level and the class level. All the methods of the respective class are included for logging for the classes that have the latter mentioned annotation. The format of a method log entry is as follows:

Format
timestamp | correlationID | threadName | duration | callType | className | methodName | methodArguments
Example
2018-11-28 10:10:56,293|a783f7c3-647f-4d10-9b72-106faa01bba8|PassThroughMessageProcessor-3|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.security.CORSRequestHandler|handleRequest|[messageContext]
 Click here for more details on the method call log entry.

The following is a detailed description of the method call log entry.

timestamp

The time at which the log is created.

Example
2018-11-28 10:10:56,293
correlationID

Each log contains a correlation ID, which is unique to the HTTP request. A client can send a unique correlation ID in the header of the HTTP request. If this correlation ID is missing in the incoming request, WSO2 API-M will generate a random correlation ID for the request.

The HTTP header that carries the correlation ID is configured in WSO2 API-M.

Example
a783f7c3-647f-4d10-9b72-106faa01bba8
threadName

The identifier of the thread.

Example
PassThroughMessageProcessor-3
duration

The time gap (in milliseconds) between two states of the message.

Example
0
callType

METHOD - The call type is METHOD in order to indicate that it is a method level log.

className
Class name of the method which was invoked.
methodName
Name of the method which was invoked.
methodArguments
Parameters of the method that was invoked.

If you need to log all the methods that correspond to a package, you need to specify the package name as the value of the logAllMethods system property. For more information, see Logging all methods.

External call logs

You can enable correlation logs in WSO2 API-M to track the complete round trip of an individual HTTP message, which means the monitoring of individual HTTP requests from the point that a message is received by WSO2 API-M until the corresponding response message is sent back to the original message sender (client → API-M → back-end → API-M → client). Thereby, you can use the correlation log file to monitor and analyze external calls in detail. The following are the two types of external call logs that can be tracked via observability in WSO2 API-M.

Synapse global handler level external call logs

All external calls done by the API Manager is logged via this category. Note that this does not include DB calls. This is done via a Synapse Global Handler that logs the important information of the external calls. The format for a Synapse global handler level external call log entry is as follows:

Format
timestamp | correlationID | threadName | duration(BE latency) | callType | apiName | apiMethod | apiContext | apiResourcePath | authHeader | orgIdHeader | SrcIdHeader | applIdHeader | uuIdHeader | requestSize | responseSize | apiResponseStatusCode | applicationName | consumerKey | responseTime
Example
2018-11-28 10:10:56,316|a783f7c3-647f-4d10-9b72-106faa01bba8|PassThroughMessageProcessor-4|20|HTTP|admin--PizzaShackAPI:v1.0.0|GET|/pizzashack/1.0.0/menu|pizzashack/1.0.0/menu|null|null|null|null|null|71|2238|200|DefaultApplication|Fslkdjfnlsdfjiefnlsdf|21
 Click here for more details on the Synapse global handler level external call log entry.

The following is a detailed description of the Synapse global handler level external call log entry.

timestamp

The time at which the log is created.

Example
2018-11-28 10:10:56,316
correlationID

Each log contains a correlation ID, which is unique to the HTTP request. A client can send a unique correlation ID in the header of the HTTP request. If this correlation ID is missing in the incoming request, WSO2 API-M will generate a random correlation ID for the request.

The HTTP header that carries the correlation ID is configured in WSO2 API-M.

Example
a783f7c3-647f-4d10-9b72-106faa01bba8
threadName

The identifier of the thread.

Example
PassThroughMessageProcessor-4
duration(BE latency)

The time gap (in milliseconds) between two states of the message.

Example
20
callType

HTTP - The call type identifies logs that correspond to either back-end latency or round-trip latency states. Thereby, in the case of an individual request, one log will be recorded to identify back-end latency, and another log for the round-trip latency. These logs are categorized using the HTTP call type because these logs relate to HTTP calls between WSO2 API-M and external clients.

apiName

Name of the API that was invoked.


Example
admin--PizzaShackAPI:v1.0.0
apiMethod

HTTP method utilized.

Example
GET
apiContext

The API context which was invoked.

Example
/pizzashack/1.0.0/menu
apiResourcePath

Resource path of the API that was invoked.

Example
/pizzashack/1.0.0/menu
authHeader
Logs the Authorization header.
orgIdHeader

Logs the organization-id header.

SrcIdHeader

Logs the source-id header.

applIdHeader

Logs the application-id header.

uuIdHeader

Logs the uuid header.

requestSize

Size of the request payload.

Example
71
responseSize

Size of the response payload.

Example
2238
apiResponseStatusCode

Status code of the response.

Example
200
applicationName

Name of the application that was used to subscribe to the API.

Example
DefaultApplication
consumerKey

This refers to the consumer key that you get when you generate keys for your production and sandbox environments.

Example
Fslkdjfnlsdfjiefnlsdf
responseTime

Roundtrip time of the request.

Example
21

Synapse passthrough transport level external call logs

In contrast to the information provided by the Synapse global handler level, the passthrough transport level gives certain additional data such as, the Synapse internal state of the request. The format for a Synapse passthrough transport level external call log entry is as follows:

Format
timestamp|correlationID|threadName|duration|callType|connectionName|methodType|connectionURL|httpState
Example - HTTP State Transition
2018-11-28 10:10:56,314|a783f7c3-647f-4d10-9b72-106faa01bba8|HTTPS-Sender I/O dispatcher-1|1|HTTP State Transition|http-outgoing-1|GET|https://localhost:9443/am/sample/pizzashack/v1/api/menu|RESPONSE_DONE
 Click here for more details on the Synapse passthrough transport level external call log entry.

The following is a detailed description of the Synapse passthrough transport level external call log entry.

timestamp

The time at which the log is created.

Example
2018-11-28 10:10:56,314
correlationID

Each log contains a correlation ID, which is unique to the HTTP request. A client can send a unique correlation ID in the header of the HTTP request. If this correlation ID is missing in the incoming request, WSO2 API-M will generate a random correlation ID for the request.

The HTTP header that carries the correlation ID is configured in WSO2 API-M.

Example
a783f7c3-647f-4d10-9b72-106faa01bba8
threadName

The identifier of the thread.

Example
HTTPS-Sender I/O dispatcher-1
duration

The time gap (in milliseconds) between two states of the message.

Example
1
callType

The following are the two possible call types:

  • HTTP - This call type identifies logs that correspond to either back-end latency or round-trip latency states. Thereby, in the case of an individual request, one log will be recorded to identify back-end latency, and another log for the round-trip latency. These logs are categorized using the HTTP call type because these logs relate to HTTP calls between WSO2 API-M and external clients.
  • HTTP State Transition - This call type idenfities logs that correspond to the state transition in the HTTP transport related to a particular message.
connectionName

This is a name that is generated to identify the connection between WSO2 API-M and the external client (back-end or message sender).

Example
http-outgoing-1
methodType

The HTTP method used for the request.

Example
GET
connectionURL

The connection URL of external client to which the message is passed from WSO2 API-M.

Example
https://localhost:9443/am/sample/pizzashack/v1/api/menu
httpState

Listed below are the state changes that a message goes through when it flows through WSO2 API-M, and when the message flows between WSO2 API-M and exernal clients. A new log is generated for the message to record each of the following states.

  • REQUEST_HEAD: All HTTP headers in the incoming request are being written to the backend.
  • REQUEST_BODY: The body of the incoming request is being written to the backend.
  • REQUEST_DONE: The request is completely received (content decoded) and written to the backend.
  • BACKEND LATENCY: The response message is received by WSO2 API-M. This status corresponds to the time total time taken by the backend to process the message.
  • RESPONSE_HEAD: All HTTP headers in the response message are being written to the client.
  • RESPONSE_BODY: The body of the response message is being written to the client.
  • RESPONSE_DONE: The response is completely received and written to the client.
  • ROUND-TRIP LATENCY: The response message is completely writtent to the client. This status corresponds to the total time taken by the HTTP request to compete the round trip (from the point of receiving the HTTP request from a client until the response message is sent back to the client)

Database call logs

The database call logging for observability includes two types of DB calls, namely LDAP calls and JDBC calls. This will help to track down any latencies caused by a database calls in an instance.

The format for a database call log entry is as follows:

  • JDBC call logs

    Format
    timestamp | correlationID | threadID | duration | callType | startTime | methodName | query | connectionUrl
    Example
    2018-11-28 10:10:43,202|a783f7c3-647f-4d10-9b72-106faa01bba8|PassThroughMessageProcessor-1|0|jdbc|1543380043202|executeQuery|SELECT REG_NAME, REG_VALUE FROM REG_PROPERTY P, REG_RESOURCE_PROPERTY RP WHERE P.REG_ID=RP.REG_PROPERTY_ID AND RP.REG_VERSION=? AND P.REG_TENANT_ID=RP.REG_TENANT_ID AND RP.REG_TENANT_ID=?|jdbc:h2:repository/database/WSO2CARBON_DB
     Click here for more details on the JDBC call log entry.

    The following is a detailed description of the JDBC call log entry.

    timestamp

    The time at which the log is created.

    Example
    2018-11-28 10:10:43,202
    correlationID

    Each log contains a correlation ID, which is unique to the HTTP request. A client can send a unique correlation ID in the header of the HTTP request. If this correlation ID is missing in the incoming request, WSO2 API-M will generate a random correlation ID for the request.

    The HTTP header that carries the correlation ID is configured in WSO2 API-M.

    Example
    a783f7c3-647f-4d10-9b72-106faa01bba8
    threadName

    The identifier of the thread.

    Example
    PassThroughMessageProcessor-1
    duration

    The time gap (in milliseconds) between two states of the message.

    Example
    0
    callType

    jdbc - This indicates JDBC level logs

    startTime

    Time in milliseconds at which the query started.

    Example
    1543380043202
    methodName

    SQL statement method type that was called.

    Example
    executeQuery
    query

    SQL query

    Example
    SELECT REG_NAME, REG_VALUE FROM REG_PROPERTY P, REG_RESOURCE_PROPERTY RP WHERE P.REG_ID=RP.REG_PROPERTY_ID AND RP.REG_VERSION=? AND P.REG_TENANT_ID=RP.REG_TENANT_ID AND RP.REG_TENANT_ID=?
    connectionUrl

    Database connection URL

    Example
    jdbc:h2:repository/database/WSO2CARBON_DB

  • LDAP call logs

    Format
    timestamp | correlationID | threadID | duration | callType | startTime | methodName | providerUrl | principal | argsLengeth | args
    Example
    2018-11-0514:05:18,599|86b56b19-7872-4e2f-84f3-5a14f92e18c1|http-nio-9443-exec-8|200|ldap|1541406918591|search|ldap://localhost:10389|uid=admin,ou=system|3| uid=admin,ou=Users,dc=WSO2,dc=ORG,(&(objectClass=person)(uid=admin)),javax.naming.directory.SearchControls@548e9a48
     Click here for more details on the LDAP call log entry.

    The following is a detailed description of the LDAP call log entry.

    timestamp

    The time at which the log is created.

    Example
    2018-11-0514:05:18,599
    correlationID

    Each log contains a correlation ID, which is unique to the HTTP request. A client can send a unique correlation ID in the header of the HTTP request. If this correlation ID is missing in the incoming request, WSO2 API-M will generate a random correlation ID for the request.

    The HTTP header that carries the correlation ID is configured in WSO2 API-M.

    Example
    86b56b19-7872-4e2f-84f3-5a14f92e18c1
    threadName

    The identifier of the thread.

    Example
    http-nio-9443-exec-8
    duration

    The time gap (in milliseconds) between two states of the message.

    Example
    200
    callType
    		ldap - Determines the LDAP level logs
    startTime

    Time in milliseconds at which the query started.

    Example
    1541406918591
    methodName

    IDAP method type that was called.

    Example
    search
    providerUrl

    LDAP connection URL.

    Example
    ldap://localhost:10389
    principal

    Login name of the user.

    Example
    uid=admin,ou=system
    argsLengeth

    Length of arguments.

    3
    args

    Arguments in the LDAP query.

    Example
    uid=admin,ou=Users,dc=WSO2,dc=ORG,(&(objectClass=person)(uid=admin)),javax.naming.directory.SearchControls@548e9a48

Using the correlation logs

Follow the instructions below to check the correlation logs:

Step 1 - Setup WSO2 API-M

Enable observability with WSO2 API-M and start the WSO2 API-M server.
For more information, see Enabling observability with WSO2 API-M.

Step 2 - Invoke an API

Follow the instructions below to invoke an API.

  1. Create and publish an API.
    For more information, see Create and Publish an API.
  2. Subscribe to an API.
    For more information, see steps 1 to 10 under Subscribe to an API.

  3. Invoke the API.
    The following is based on the PhoneVerification API.

Step 3 - Check the correlation logs

  1. Open a terminal and navigate to the <API-M_HOME>/repository/logs directory where the correlation.log file is saved.

  2. Isolate the logs that are correlated.
    Replace <correlation_ID> with the required value.

    cat correlation.log | grep "<correlation_ID>"

Reading and analyzing the correlation logs

Let's analyze the following sample correlation log.

2018-11-29 15:19:13,859|ff0c8866-d8a8-4189-930d-016b9d92f1e8|HTTP-Listener I/O dispatcher-2|1|HTTP State Transition|http-incoming-2|GET|/testing/1|REQUEST_HEAD

2018-11-29 15:19:13,859|ff0c8866-d8a8-4189-930d-016b9d92f1e8|HTTP-Listener I/O dispatcher-2|0|HTTP State Transition|http-incoming-2|GET|/testing/1|REQUEST_DONE

2018-11-29 15:19:13,862|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-17|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.security.CORSRequestHandler|handleRequest|[messageContext]

2018-11-29 15:19:13,863|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-17|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.security.APIKeyValidator|getResourceCache|[]

2018-11-29 15:19:13,863|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-17|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.security.APIKeyValidator|getResourceAuthenticationScheme|[synCtx]

2018-11-29 15:19:13,863|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-17|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.security.AuthenticationContext|getCallerToken|[]

2018-11-29 15:19:13,863|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-17|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.security.oauth.OAuthAuthenticator|authenticate|[synCtx]

2018-11-29 15:19:13,863|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-17|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.security.APIAuthenticationHandler|handleRequest|[messageContext]

2018-11-29 15:19:13,863|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-17|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.throttling.ThrottleHandler|doThrottle|[messageContext]

2018-11-29 15:19:13,863|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-17|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.analytics.APIMgtUsageHandler|handleRequest|[mc]

2018-11-29 15:19:13,864|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-17|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.analytics.APIMgtGoogleAnalyticsTrackingHandler|handleRequest|[msgCtx]

2018-11-29 15:19:13,864|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-17|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler|mediate|[messageContext, direction]

2018-11-29 15:19:13,864|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-17|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler|handleRequest|[messageContext]

2018-11-29 15:19:13,984||pool-10-thread-1|0|jdbc|1543484953984|executeQuery|SELECT REG_PATH, REG_USER_ID, REG_LOGGED_TIME, REG_ACTION, REG_ACTION_DATA FROM REG_LOG WHERE REG_LOGGED_TIME>? AND REG_LOGGED_TIME<? AND REG_TENANT_ID=? ORDER BY REG_LOGGED_TIME DESC|jdbc:h2:repository/database/WSO2CARBON_DB

2018-11-29 15:19:13,984||pool-10-thread-1|0|jdbc|1543484953984|executeQuery|SELECT UM_ID, UM_DOMAIN_NAME, UM_EMAIL, UM_CREATED_DATE, UM_ACTIVE FROM UM_TENANT ORDER BY UM_ID|jdbc:h2:repository/database/WSO2CARBON_DB

2018-11-29 15:19:14,031|ff0c8866-d8a8-4189-930d-016b9d92f1e8|HTTP-Sender I/O dispatcher-3|3|HTTP State Transition|http-outgoing-3|GET|http://0.0.0.0:10080/hello/sayHello|REQUEST_DONE

2018-11-29 15:19:14,863|ff0c8866-d8a8-4189-930d-016b9d92f1e8|HTTP-Sender I/O dispatcher-3|832 |HTTP|http://0.0.0.0:10080/hello/sayHello|BACKEND LATENCY

2018-11-29 15:19:14,864|ff0c8866-d8a8-4189-930d-016b9d92f1e8|HTTP-Sender I/O dispatcher-3|832|HTTP State Transition|http-outgoing-3|GET|http://0.0.0.0:10080/hello/sayHello|RESPONSE_HEAD

2018-11-29 15:19:14,864|ff0c8866-d8a8-4189-930d-016b9d92f1e8|HTTP-Sender I/O dispatcher-3|1|HTTP State Transition|http-outgoing-3|GET|http://0.0.0.0:10080/hello/sayHello|RESPONSE_BODY

2018-11-29 15:19:14,864|ff0c8866-d8a8-4189-930d-016b9d92f1e8|HTTP-Sender I/O dispatcher-3|0|HTTP State Transition|http-outgoing-3|GET|http://0.0.0.0:10080/hello/sayHello|RESPONSE_DONE

2018-11-29 15:19:14,868|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-18|1003|HTTP|admin--test:v1|GET|/testing/1/*|testing/1|null|null|null|null|null|71|73|200|DefaultApplication|AwlPOz2aDf2i1gZFWgITEgf4oPsa|1005

2018-11-29 15:19:14,868|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-18|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.security.CORSRequestHandler|handleResponse|[messageContext]

2018-11-29 15:19:14,868|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-18|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.security.APIAuthenticationHandler|handleResponse|[messageContext]

2018-11-29 15:19:14,868|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-18|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.throttling.ThrottleHandler|handleResponse|[messageContext]

2018-11-29 15:19:14,868|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-18|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.analytics.APIMgtUsageHandler|handleResponse|[mc]

2018-11-29 15:19:14,868|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-18|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.analytics.APIMgtGoogleAnalyticsTrackingHandler|handleResponse|[arg0]

2018-11-29 15:19:14,868|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-18|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler|mediate|[messageContext, direction]

2018-11-29 15:19:14,868|ff0c8866-d8a8-4189-930d-016b9d92f1e8|PassThroughMessageProcessor-18|0|METHOD|org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler|handleResponse|[messageContext]

2018-11-29 15:19:14,870|ff0c8866-d8a8-4189-930d-016b9d92f1e8|HTTP-Listener I/O dispatcher-2|1011|HTTP State Transition|http-incoming-2|GET|/testing/1|RESPONSE_HEAD

2018-11-29 15:19:14,871|ff0c8866-d8a8-4189-930d-016b9d92f1e8|HTTP-Listener I/O dispatcher-2|1|HTTP State Transition|http-incoming-2|GET|/testing/1|RESPONSE_BODY

2018-11-29 15:19:14,871|ff0c8866-d8a8-4189-930d-016b9d92f1e8|HTTP-Listener I/O dispatcher-2|0|HTTP State Transition|http-incoming-2|GET|/testing/1|RESPONSE_DONE

2018-11-29 15:19:14,871|ff0c8866-d8a8-4189-930d-016b9d92f1e8|HTTP-Listener I/O dispatcher-2|1012|HTTP|http-incoming-2|GET|/testing/1|ROUND-TRIP LATENCY


Line No:

Description
1-2HTTP State Transition when receiving the request
3-13Methods invoked in Gateway handlers in the request path
14-15Database calls relevant to the API call
16HTTP State Transition for the request
17

Backend Latency
Here the backend latency log have reflected the 800ms delay that was added to the backend for this example.

18-20HTTP State Transition for response
21Synapse global handler level for the backend call log
22-28Methods invoked in the Gateway handlers in the response path
29-31HTTP State Transition for dispatching response
32HTTP Roundtrip Latency

Using these logs we can determine that the latency is caused by the backend call.

Advanced use cases

The following are the advanced use cases that you may run into when working with observability in WSO2 API-M.

Logging all methods

Currently, when using method logging, it only logs special methods that are suspected to give latencies, because logging all methods can pose performance issues. There can be instances where you may need to log other methods too.

Follow the instructions below to configure the logging of all methods.

Blacklisting threads

Blacklisting of threads is needed because some threads keep on printing unnecessary logs continuously. Therefore, by blacklisting unwanted threads from printing logs it helps in terms of readability of the logs.

Follow the instructions below to enable blacklisting of threads:


If the above configuration is not added, by default the MessageDeliveryTaskThreadPool thread will be blacklisted as it is found to print a considerable amount for messages for API-M instances. However, if the above configuration is added the default value will be overridden. 

Blacklisting of threads is not needed by default, as all unnecessary threads are already blacklisted.

com.atlassian.confluence.content.render.xhtml.migration.exceptions.UnknownMacroMigrationException: The macro 'next_previous_links2' is unknown.