Tracking and Log Filtering

To enable log messages to be tracked and analyzed more effectively log management tools such as Splunk enable indexing of key value pairs through formatting of plain text in a specific format.  This gives operations more power to filter messages based on specific criteria.  The base logger is a simple way of constructing those key value pairs so that each request has a stored copy that it can append to the base of every log message.

​To construct the base logger we set the key value pairs in a variable.

<sub-flow name="set-baseLogger">
     <set-variable 
          variableName="baseLogger" 
          value="#['application="${app.name}" messageId="' ++ uuid() ++ '" correlationId="' ++ (attributes.headers.'correlation_id' default ‘’ )++ '"']"
     />
</sub-flow>

The filters are formatted using key value pairs in a format indexable by Splunk.  This format is key=”value”.  Key value pairs should include useful values for tracking and filtering.

To reference the base logger you must add it in the following location.

1. For applications using APIKit Router add the base logger in the main flow before you call the APIKit Router.

<flow name="main-api">
     <http:listener config-ref="httpListener" path="/api/demo/*"/>
      <flow-ref name="set-baseLogger" doc:name="set-baseLogger"/>
      <apikit:router config-ref="router-config" />
      <error-handler ref="default-errorhandler"/>
</flow>

2. For applications not using the APIKit Router such as batch or listener endpoints, add the base logger in the main flow straight after the entry point (listener, scheduler, etc…).

​Each time a message is logged the key value pairs stored in the variable are appended to the base of the log message.

<logger level="INFO" message="#[vars.baseLogger] write something here..."/>

Instrumentation

Instrumentation allows operations to monitor and measure the performance of an application.  This is typically done through enabling logging on major components of execution.

It is recommended to add logging in the following places:

• At the start and end of each service.
• At the start and end of any outbound system call.

Logging is meant to be informative so log lines should be structured in a way that makes sense to the operations team.  Some suggestions would include:

• Each log line for an endpoint should include the Flow Name, Request or Response, and a payload or any parameters that are received or returned.
• Each log line for an outbound system call should include the name of the system being called, and a payload or any parameters that are received or returned.

The out-of-the-box behavior from log4j will log timestamps.  The base logger will log all the key value pairs for filtering.  When structuring the logging for instrumentation, it is recommended that you work out how you are going to query your logs first and then define the logging format that enables those queries.

For example:
index=”mule” | stats latest(_time) as response earliest(_time) as request by correlationId, messageId, application | eval duration = response – request | table application, duration, correlationId, messageId, request, response | sort by duration desc

Error Types

Execution failures are represented with Mule errors that have the following components:

• A description of the problem.
• A type that is used to characterize the problem.
• A cause, the underlying Java Throwable that resulted in the failure.
• An optional error message, which is used to include a proper Mule Message regarding the problem.

Error types consist of both a namespace and an identifier, allowing you to distinguish the types according to their domain.  Error types are formatted in the exception as namespace: identifier.

Error types can have a parent type, enabling errors to be categorized into broader categories so that they can be handled more generically if necessary.   Below is a diagram of what the core runtime hierarchy looks like:

While connectors define their own namespace, core runtime errors have an implicit one.

Connectors inherit a set of common error types such as CONNECTIVITY and RETRY_EXHAUSTED.  Each connector then extends on these common error types to define their own error type hierarchy specific to their application.

Error Handling

The whole point of error handling is to leverage the error types so that errors are reported and structured in a way that is easy to diagnose.  Error handling should use the out-of-the-box error types provided when an exception occurs to categorize the errors into alerts and dashboards.

The role of the error handler should be:

1. Write an alert message to the logs as log level error consisting of base logger, plus two more key value pairs for the error type and error message.
2. Create a response back to the caller.
3. (optional) Set payload on a retry queue.

In this example error handler, we execute the following logic.

• Determine the HTTP Status Code based on error type.

<error-handler name=" template-errorhandler">
     <on-error-propagate type="CONNECTIVITY" logException="true" enableNotifications="true">
         <set-variable variableName="httpStatus" value="504"/>
          <flow-ref name="handle-error" doc:name="handle-error"/>
     </on-error-propagate>
     <on-error-propagate type="SECURITY" logException="true" enableNotifications="true">
         <choice>
             <when expression="#[error.errorType.identifier == 'UNAUTHORIZED']">
                  <set-variable variableName="httpStatus" value="401"/>
             </when>
             <otherwise>
                    <set-variable variableName="httpStatus" value="403"/>
             </otherwise>
         </choice>
         <flow-ref name="handle-error" doc:name="handle-error"/>
      </on-error-propagate>
       <on-error-propagate type="ANY" logException="true" enableNotifications="true">
           <choice>
               <when expression="#[error.errorType.namespace == 'APIKIT']">
                   <choice>
                        <when expression="#[error.errorType.identifier == 'BAD_REQUEST']">
                            <set-variable variableName="httpStatus" value="400" />
                        </when>
                        <when expression="#[error.errorType.identifier == 'NOT_FOUND']">
                            <set-variable variableName="httpStatus" value="404" />
                         </when>
                        <when expression="#[error.errorType.identifier == 'METHOD_NOT_ALLOWED']">
                            <set-variable variableName="httpStatus" value="405" />
                        </when>
                        <when expression="#[error.errorType.identifier == 'NOT_ACCEPTABLE']">
                            <set-variable variableName="httpStatus" value="406" />
                        </when>
                        <when expression="#[error.errorType.identifier == 'UNSUPPORTED_MEDIA_TYPE']">
                            <set-variable variableName="httpStatus" value="415" />
                        </when>
                       <when expression="#[error.errorType.identifier == 'NOT_IMPLEMENTED']">
                           <set-variable variableName="httpStatus" value="501" />
                       </when>
              </choice>
         </when>
         <otherwise>
             <set-variable variableName="httpStatus" value="500" />
         </otherwise>
      </choice>
      <flow-ref name="handle-error" doc:name="handle-error"/>
   </on-error-propagate>
</error-handler>

• Write out the log filters with additional key value pairs for error type and description.
• Construct the response to the caller.

<sub-flow name="handle-error">
    <logger level="ERROR" message='#[vars.baselogger] type="#[error.errorType.namespace]:#[error.errorType.identifier]" error="#[error.description]"' doc:name="Log Error Message "/>
     <ee:transform doc:name="Transform Error Response" doc:id="6b1e7e5d-4e20-47dc-80e2-265d0ce839f3">
          <ee:message >
              <ee:set-payload ><![CDATA[%dw 2.0
             output application/json
             ---
            {
            "error": error.description,
            "type": error.errorType.namespace ++ ":" ++ error.errorType.identifier
             }]]></ee:set-payload>
        </ee:message>
    </ee:transform>
</sub-flow>