When to Log in our Mule Apps

byGonzalo Marcos -

In this series of posts, we’re going through the different steps necessary to define our Logging Strategy for Mule. In the previous posts, we discussed:
Please head over to those articles before reading this one. Once we know what our goals for logging are and what different pieces of information we could log to help those goals, now it’s time to answer the question - when should we log? At which part of our app should I include a logger processor?

Logging in a Mule application should be strategically placed to capture critical information that aids in monitoring, debugging, and auditing. 

In this post we’ll see some key points in a Mule application where logging is particularly important:

1. At the Start of a Flow or Subflow

  • Purpose: Capture the beginning of a transaction or process. This helps in tracing the lifecycle of a request.
  • What to Log:
    • Entry point of the flow.
    • Incoming request details (e.g., HTTP method, headers, payload).
    • Any relevant business identifiers (e.g., order ID, customer ID).
  • Example:
<logger level="INFO" message="Starting orderProcessingFlow for OrderID #[attributes.queryParams.orderId]"/>


2. After Receiving or Sending External Requests

  • Purpose: Capture the interaction between the Mule application and external systems (e.g., APIs, databases).
  • What to Log:
    • Outbound request details (e.g., endpoint, payload).
    • Response from external systems, including status codes and any error messages.
    • Time taken to receive a response (for performance monitoring).
  • Example:
<logger level="INFO" message="Sending request to Payment Gateway API. Payload: #[message.payload]"/>
<logger level="INFO" message="Received response from Payment Gateway API. Status Code: #[attributes.statusCode], Response: #[message.payload]"/>


3. Before and After Key Processing Steps

  • Purpose: Track progress through significant steps in the flow, making it easier to identify where issues occur.
  • What to Log:
    • Important business logic execution, like validation, transformation, or decision points.
    • Intermediate data states that are relevant for debugging or auditing.
  • Example:
<logger level="INFO" message="Transforming order data for OrderID #[vars.orderId]"/>


4. In Error Handling Scenarios

  • Purpose: Capture information when something goes wrong, which is crucial for debugging and troubleshooting.
  • What to Log:
    • Exception details (e.g., exception message, stack trace).
    • Failed request/response data.
    • Context about what was being attempted when the error occurred.
  • Example:
<error-handler name="logging-strategyError_Handler" doc:id="fe82cafc-1e92-453f-a441-8326f45e6de8" >
        <on-error-propagate enableNotifications="true" logException="true" doc:name="On Error Propagate" doc:id="69481fb4-7d5c-4a65-b5a4-7254f77a4444" >
            <logger level="ERROR" message="Error processing OrderID #[vars.orderId]: #[exception.message]" />
            <logger level="ERROR" message="Stack Trace: #[exception.stackTrace]" />
        </on-error-propagate>
    </error-handler>


5. On Success or Completion of a Process

  • Purpose: Confirm the successful completion of a flow/subflow or significant process.
  • What to Log:
    • Confirmation that the process completed successfully.
    • Any resulting data or key outcomes (e.g., transaction ID, response payload).
    • Performance metrics like execution time.
  • Example:
<logger level="INFO" message="Successfully processed OrderID #[vars.orderId]. Execution time: #[vars.executionTime]ms"/>


6. During Conditional Logic

  • Purpose: Capture decisions made in the flow, especially in branches or complex conditional logic.
  • What to Log:
    • The condition evaluated and the path taken.
    • Any key variables or data that influenced the decision.
  • Example:
<choice doc:name="Check Order Amount">
<when expression="#[vars.orderAmount > 1000]">
<logger level="INFO" message="OrderID #[vars.orderId] is flagged for manual review due to high amount"/>
</when>
<otherwise>
<logger level="INFO" message="OrderID #[vars.orderId] is within normal range"/>
</otherwise>
</choice>


7. At Regular Intervals in Long-Running Processes

  • Purpose: Provide updates on the progress of long-running processes, such as batch jobs or asynchronous operations.
  • What to Log:
    • Status updates indicating the progress.
    • Intermediate results or milestones reached.
  • Example:
<logger level="INFO" message="Processed #[vars.recordsProcessed] of #[vars.totalRecords] orders in batch job"/>


8. During Transaction Boundaries

  • Purpose: Track the start and end of transactions, including commits and rollbacks.
  • What to Log:
    • Start of a transaction.
    • Commit or rollback events, along with outcomes.
    • Any issues encountered during transaction handling.
  • Example:
<logger level="INFO" message="Transaction started for OrderID #[vars.orderId]"/>
<logger level="INFO" message="Transaction committed for OrderID #[vars.orderId]"/>


9. For Security and Compliance

  • Purpose: Ensure that security-sensitive events are logged for compliance and auditing purposes.
  • What to Log:
    • Authentication and authorization events (e.g., successful and failed logins).
    • Access to sensitive data or resources.
    • Changes to configuration or access control settings.
  • Example:
<logger level="INFO" message="User #[vars.username] authenticated successfully"/>


10. During Resource Access (e.g., File, Database, Queue)

  • Purpose: Monitor access to and operations on external resources, such as files, databases, or message queues.
  • What to Log:
    • Access details like file paths, database queries, or queue names.
    • Results of operations (e.g., file read/write status, query results, messages sent/received).
  • Example:
<logger level="INFO" message="Querying database for CustomerID #[vars.customerId]"/>
<logger level="INFO" message="Query result: #[payload]"/>


11. When Entering and Exiting Subflows or Components

  • Purpose: Trace entry and exit points within reusable subflows or components.
  • What to Log:
    • Entry and exit messages, including relevant parameters passed to the subflow or component.
    • Any changes made to the payload or variables within the subflow.
  • Example:
<logger level="DEBUG" message="Entering processOrderSubflow with OrderID #[vars.orderId]"/>
<logger level="DEBUG" message="Exiting processOrderSubflow"/>


12. For Performance Monitoring

  • Purpose: Capture performance metrics to identify bottlenecks or inefficiencies.
  • What to Log:
    • Execution time of significant operations or the entire flow.
    • Resource utilization if applicable (e.g., memory, CPU usage).
  • Example:
<set-variable variableName="startTime" value="#[now()]"/>
<!-- Some processing -->
<set-variable variableName="executionTime" value="#[now() - vars.startTime]"/>
<logger level="INFO" message="Processing time: #[vars.executionTime] ms"/>


13. During Integration with Third-Party Services

  • Purpose: Capture the interaction with third-party services, which can be a common point of failure.
  • What to Log:
    • Requests sent to and responses received from third-party APIs or services.
    • Any errors or unexpected responses, including retries if applicable.
  • Example:
<logger level="INFO" message="Calling external API with payload #[payload]"/>
<logger level="ERROR" message="Failed to receive a valid response from external API. Error: #[exception.message]"/>


14. During Data Transformation

  • Purpose: Track data as it undergoes transformations, particularly in complex or critical transformations.
  • What to Log:
    • Input and output of transformations (e.g., DataWeave scripts).
    • Any issues or exceptions during transformation.
  • Example:
<logger level="DEBUG"
 message="Transforming input payload: #[message.payload]" />
 <!-- DataWeave transformation here -->
 <logger level="DEBUG"
 message="Transformed payload: #[message.payload]" />


15. In Orchestration Scenarios

  • Purpose: Log interactions between different systems or services orchestrated by Mule, especially in middleware scenarios.
  • What to Log:
    • Details of messages passed between services.
    • Sequence of service calls.
    • Any mediation logic applied.
  • Example:
<logger level="INFO" message="Orchestrating service calls: Service1 -> Service2 -> Service3"/>
<logger level="INFO" message="Service1 response: #[vars.service1Response]"/>


16. During Retry or Circuit Breaker Events

  • Purpose: Monitor retry mechanisms or circuit breaker activations to understand how often they’re triggered and their outcomes.
  • What to Log:
    • Attempt number and outcome of each retry.
    • Circuit breaker state changes (e.g., open, closed, half-open).
    • Final outcome after retries or circuit breaker activation.
  • Example:
<logger level="WARN" message="Retry attempt #[vars.retryCount] for OrderID #[vars.orderId]"/>
<logger level="ERROR" message="Circuit breaker opened for service call to Payment Gateway after multiple failures"/>


17. When Handling Large Payloads or Batch Processing

  • Purpose: Track the processing of large payloads or batch jobs, especially where performance or partial failures are a concern.
  • What to Log:
    • Start and end of batch jobs.
    • Progress updates, such as number of records processed.
    • Any partial failures or retries within the batch.
  • Example:
<logger level="INFO"
            message="Starting batch job for processing 10,000 records" />
        <batch:job jobName="ProcessLargeOrdersBatch">
            <batch:process-records>
                <logger level="INFO"
                    message="Processing record #[vars.recordId]" />
            </batch:process-records>
        </batch:job>
        <logger level="INFO"
            message="Completed batch job. Total records processed: #[vars.totalProcessed]" />


18. During Dynamic Configuration or Routing

  • Purpose: Capture decisions made by dynamic configuration or routing logic, which might vary based on runtime conditions.
  • What to Log:
    • Configuration values or routes chosen.
    • Any conditions or rules evaluated to make decisions.
  • Example:
<logger level="INFO" message="Routing order to fulfillment center: #[vars.fulfillmentCenter]"/>
<logger level="DEBUG" message="Dynamic configuration applied: MaxRetryCount = #[vars.maxRetryCount]"/>


19. For Cache Operations

  • Purpose: Log cache interactions, especially when caching is used to optimize performance or reduce load on external systems.
  • What to Log:
    • Cache hits and misses.
    • Data added to or retrieved from the cache.
    • Any cache invalidation or eviction events.
  • Example:
<logger level="DEBUG" message="Cache hit for OrderID #[vars.orderId]"/>
<logger level="DEBUG" message="Adding data to cache: #[vars.cacheKey]"/>


20. When Enriching Data

  • Purpose: Log the process of data enrichment, where additional information is added to a message or payload.
  • What to Log:
    • Original data and the enriched data.
    • Sources of enrichment (e.g., external APIs, databases).
    • Any issues encountered during enrichment.
  • Example:
<logger level="INFO" message="Enriching order data with customer details from Customer Service"/>
<logger level="INFO" message="Order data enriched: #[message.payload]"/>


21. For Transaction Rollback Scenarios

  • Purpose: Capture events where transactions are explicitly rolled back, either due to an error or a business rule.
  • What to Log:
    • Reason for rollback (e.g., exception, business condition).
    • Data or state at the time of rollback.
    • Outcome of the rollback operation.
  • Example:
<logger level="WARN" message="Transaction rolled back for OrderID #[vars.orderId] due to #[exception.message]"/>


22. For Auditing and Compliance

  • Purpose: Log specific events or data changes to meet auditing and compliance requirements, such as GDPR or financial regulations.
  • What to Log:
    • User actions (e.g., data access, modifications).
    • Sensitive data handling (e.g., encryption, anonymization).
    • Consent or policy-related actions.
  • Example:
<logger level="INFO" message="User #[vars.userId] accessed PII data for CustomerID #[vars.customerId]"/>
<logger level="INFO" message="Data anonymized for compliance with GDPR: #[message.payload]"/>


23. For Event-Driven Architecture

  • Purpose: Log events in event-driven or reactive architectures to ensure traceability of events and their handling.
  • What to Log:
    • Event creation and publication.
    • Event consumption and processing.
    • Any issues or delays in event handling.
  • Example:
<logger level="INFO" message="Published event: OrderCreated for OrderID #[vars.orderId]"/>
<logger level="INFO" message="Consumed event: OrderCreated for OrderID #[vars.orderId]"/>


24. During Resource Cleanup or Finalization

  • Purpose: Ensure that resource cleanup operations (e.g., closing connections, releasing locks) are logged, particularly in error-prone areas.
  • What to Log:
    • Successful release or cleanup of resources.
    • Any issues encountered during cleanup.
  • Example:
<logger level="INFO" message="Closing database connection for OrderID #[vars.orderId]"/>
<logger level="ERROR" message="Failed to release file lock on #[vars.filePath]: #[exception.message]"/>


25. For Debugging and Development

  • Purpose: Use detailed, verbose logging during development to trace and debug complex flows. These logs can often be disabled or reduced in production.
  • What to Log:
    • Detailed execution flow, including variable states and decision points.
    • Full payloads or large data structures (use it with caution in production).
  • Example:
<logger level="DEBUG" message="Entering function calculateTotalPrice with parameters: #[vars.parameters]"/>
<logger level="DEBUG" message="Final result of price calculation: #[vars.totalPrice]"/>


26. Logging in Asynchronous Processes

  • Purpose: Log events in asynchronous or background processes to ensure visibility into their execution and any issues.
  • What to Log:
    • Start and completion of asynchronous tasks.
    • Any errors encountered during async processing.
    • Correlation with the main process or initiating event.
  • Example:
<logger level="INFO" message="Starting asynchronous processing for OrderID #[vars.orderId]"/>
<logger level="ERROR" message="Error in asynchronous processing: #[exception.message]"/>


27. During Message Routing or Content-Based Routing

  • Purpose: Capture routing decisions, especially in content-based or rule-based routing scenarios.
  • What to Log:
    • Criteria used for routing decisions.
    • The path or endpoint chosen based on the content.
  • Example:
<logger level="INFO" message="Routing to payment processor based on currency #[vars.currency]"/>


28. When Implementing Throttling or Rate Limiting

  • Purpose: Log events related to throttling or rate limiting to monitor usage patterns and identify potential issues.
  • What to Log:
    • Throttling or rate-limiting actions

By strategically placing logs at these points in your Mule application, you ensure comprehensive coverage that captures all critical aspects of the application's operation. This approach not only aids in troubleshooting and performance monitoring but also ensures compliance with security and audit requirements.
Tags
Previous Post Next Post