Nav
You are viewing an older version of this section. Click here to navigate to the latest version.

Logging in Mule

You can configure what gets logged, where it gets logged, and how by editing a configuration file that sits in your project.

Mule logs multiple messages and specific elements in your applications' flows to help you debug and keep track of events. You can also include the <logger> Element anywhere in a flow and set it up to output any message you want. By creating a configuration file, you can define what kinds of messages to log, in what way (asynchronously or synchronously), and where they get logged (such as to the console, to disk, to an endpoint or to a database).

For logging, Mule uses slf4j, which is a logging facade that discovers and uses a logging strategy from the classpath, such as log4j2 or the JDK Logger. By default, Mule includes log4j2, which is configured with a file called log4j2.xml.

The Mule server has a log4j2.xml in its conf directory, which you can customize when running the server in standalone mode. Additionally, all the examples included with Mule have log4j2.xml files in their conf directories.

Note: To view Anypoint Studio logs:

  • View Error Log Command:

    You can view logs in Studio by clicking: Anypoint Studio > About Anypoint Studio > Installation Details > Configuration tab > View Error Log

    View Error Log

    In the file menu, double-click log and a new window opens to let you read the log details.

  • Workspace Log:

    The output from View Error Log is in the workspace’s .metadata/.log file, for example:

    /Users/me/AnypointStudio/workspace/.metadata/.log
  • Project Log:

    After you run your Mule application, the log output is in the workspace’s .mule/logs/<project>.log file. For example, for project abcd:

    /Users/me/AnypointStudio/workspace/.mule/logs/abcd.log

Synchronous Versus Asynchronous Logging

By default, Mule logs messages asynchronously in version 3.6.0 and newer.

When logging synchronously, the execution of the thread that is processing your message is interrupted to wait for the log message to be fully handled before it can continue:

logger+synch

When logging asynchronously, the logging operation occurs in a separate thread, so the actual processing of your message won’t be delayed to wait for the logging to complete:

logger+asynch+alternativo

For most cases, it’s recommended that you use asynchronous logging, as it brings a substantial improvement in throughput and latency of message processing.

On the negative side of using asynchronous logging, you may find that after a system crash, some actions were performed but not logged, since log writing is performed on a separate thread that runs independently of other actions. You may also find that on occasion, you can’t avoid the action of logging something in case you need to roll back a transaction. Check the Exception Handling With Asynchronous Logging section below to see how to mitigate these problems.

Application logs may sometimes be required to be used as audit trails. In such cases, you can’t afford to loose any log message and thus you should configure your application to always use synchronous logging.

To appreciate the impact in performance between synchronous and asynchronous logging, consider the test results shown below. We ran performance tests with an application that logs about one million messages, using an increasingly higher amount of threads on each run (these threads were responsible for generating messages; the more threads, the more concurrent messages).

logging-latency-vs-concurrency.png

The above chart shows how much latency increased as we added more concurrent messages. Notice that the results of logging asynchronously are significantly closer to those of not logging anything at all. Note that each transaction implied logging 1000 messages.

Configuring Custom Logging Settings

By default, logging in Mule is done asynchronously and at a level greater than or equal to INFO, and thus discards log messages at the DEBUG or TRACE level.

If you need to use synchronized logging, adjust the logging level or define custom categories, you can configure these properties via the file $MULE_HOME/conf/log4j2.xml. This file specifies how the logger behaves. Not editing this XML file implies that you are using the default properties.

In Anypoint Studio, log4j2.xml appears in the src/main/resources path.

The default config defines the standard loggers exactly as Mule did before the introduction of asynchronous logging. The only difference is that the new config defines all loggers (including the root one) as asynchronous.

You can override this config at the domain or application level. You can create a custom file at a custom folder location and point to it in the application’s deployment properties. To do this, open the application’s mule-deploy.properties file in src/main/app and add a log.configFile property with this location specified in it. The path to the file can be either relative to the Working Directory (the folder where the runtime was started from) or an absolute path.

log.configFile=myCustomFolder/myCustomlog4j2.xml

If this deployment property isn’t set, when an application is deployed, Mule looks for a config file following a child-first pattern, as listed below:

  • Look for a file called log4j2-test.xml in the application classpath

  • Look for a file called log4j2.xml in the application classpath

  • Look for a file called log4j2-test.xml in the domain classpath

  • Look for a file called log4j2.xml in the domain classpath

  • Look for a file called log4j2-test.xml in MULE_HOME/conf

  • Look for a file called log4j2.xml in MULE_HOME/conf

  • Apply default configuration.

Here’s the default configuration for the log4j2.xml file:

Example log4j2.xml file


         
      
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
<Configuration>
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%-5p %d [%t] %c: %m%n"/>
        </Console>
    </Appenders>

    <Loggers>

        <!-- CXF is used heavily by Mule for web services -->
        <AsyncLogger name="org.apache.cxf" level="WARN"/>

        <!-- Apache Commons tend to make a lot of noise which can clutter the log-->
        <AsyncLogger name="org.apache" level="WARN"/>

        <!-- Reduce startup noise -->
        <AsyncLogger name="org.springframework.beans.factory" level="WARN"/>

        <!-- Mule classes -->
        <AsyncLogger name="org.mule" level="INFO"/>
        <AsyncLogger name="com.mulesoft" level="INFO"/>

        <AsyncRoot level="INFO">
            <AppenderRef ref="Console"/>
        </AsyncRoot>
    </Loggers>

</Configuration>
For more information on how to build this configuration file, refer to the log4j 2 configuration guide

Configuring Logs for Runtime Manager Agent

This configuration is only valid when using the Runtime Manager agent 1.5.2 and later.

If you want to log your Runtime Manager Agent state in a different location other than the default 'mule_agent.log' file, you can set up your log configuration file to do this.

You can configure your '$MULE_HOME/conf/log4j2.xml' file to include a new Log4j2 Appender called 'mule-agent-appender'. If included, the Runtime Manager Agent plugin will use this appender to log its state.

Your log4j2.xml file should include something like the following snippet to enable this functionality:


         
      
1
2
3
4
5
6
7
8
9
10
11
12
13
14
<Appenders>

  (...)

    <RollingFile name="mule-agent-appender" fileName="./logs/custom_mule_agent.log" filePattern="./logs/custom_mule_agent.log-%d{MM-dd-yyyy}.log.gz">
        <PatternLayout>
            <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
        </PatternLayout>
        <Policies>
            <TimeBasedTriggeringPolicy />
            <SizeBasedTriggeringPolicy size="250 MB"/>
        </Policies>
    </RollingFile>
</Appenders>

The above example makes the Runtime Manager agent log its state to a rolling log file in '$MULE_HOME/logs/custom_mule_agent.log', which rolls on a per day basis and until the file reaches a 250MB size.

Other Log4j2 appender configurations can be found at https://logging.apache.org/log4j/2.x/manual/appenders.html

Exception Handling With Asynchronous Logging

If you’re using asynchronous logging and experience a system crash that could have caused incomplete logs, there is an exception handler designed to help you in this situation. By default Mule registers an LMAX ExceptionHandler that logs any issues dumping log events to disk, to the console and to logs/mule_ee.log. Alternatively, you can provide your own exception handler by setting the system property AsyncLoggerConfig.ExceptionHandler to the canonical name of a class implementing the interface.

This is what the default exception handler class looks like:


         
      
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
/*
 * Copyright (c) MuleSoft, Inc.  All rights reserved.  http://www.mulesoft.com
 * The software in this package is published under the terms of the CPAL v1.0
 * license, a copy of which has been included with this distribution in the
 * LICENSE.txt file.
 */
package org.mule.module.launcher.log4j2;

import com.lmax.disruptor.ExceptionHandler;

import org.apache.logging.log4j.status.StatusLogger;

/**
 * Implementation of {@link com.lmax.disruptor.ExceptionHandler} to be used
 * when async loggers fail to log their messages. It logs this event
 * using the {@link org.apache.logging.log4j.status.StatusLogger}
 *
 * @since 3.6.0
 */
public class AsyncLoggerExceptionHandler implements ExceptionHandler
{

    private static final StatusLogger logger = StatusLogger.getLogger();

    @Override
    public void handleEventException(Throwable ex, long sequence, Object event)
    {
        logger.error("Failed to asynchronously log message: " + event, ex);
    }

    @Override
    public void handleOnStartException(Throwable ex)
    {
        logger.error("Failed to start asynchronous logger", ex);
    }

    @Override
    public void handleOnShutdownException(Throwable ex)
    {
        logger.error("Failed to stop asynchronous logger", ex);
    }
}

Unfortunately, this is not a full solution, as ultimately there is a performance-reliability trade-off between asynchronous and synchronous logging. If the risk of loosing these log messages is a serious issue, then you have no choice but to configure your loggers to be synchronous. Notice that you’re not forced to choose between making all logging synchronous or all asynchronous, you can have a mix of both.

log4j to log4j2 Migration

As of Mule runtime 3.6.0, log4j was replaced by log4j2 as the backend tool for managing logging. This implies some backwards compatibility issues as the necessary configuration files in this new framework are different. Log4j2 allows for asynchronous logging, which wasn’t previously available; Mule now implements asynchronous logging by default, as it implies a very substantial improvement in performance. Although Mule has a policy of not breaking backwards compatibility on minor releases, the extent of the improvement in performance brought by this change outweighed any inconveniences by far, and made it worthwhile to implement the change.

Migrated applications from versions of Mule that are older than 3.6.0 but use the default logging settings don’t experience any issues and keep working as normal (except that logging is asynchronous). For applications that are older than 3.6.0 and do include a custom logging configuration file – both with .xml and .properties extensions – this file isn’t recognized anymore; in these cases, logging is managed according to the default settings.

If you have issues updating your configuration files, you can find more information in the log4j 2 configuration guide or contact MuleSoft Support.

It’s highly encouraged that you implement slf4j as your logging mechanism, as the Mule project is standardized on the use of slf4j 1.7.7 .  Nevertheless, other APIs are also supported, and slf4j bridges are included in the Mule distribution to make sure that regardless of the framework you choose, log4j2 ends up handling every log event with a centralized configuration. In such a case, you must make sure not to package any logging library on your applications/extensions to avoid classpath issues between such libraries and the bridge that link to slf4j.

Configuration Reloading

By default, Mule polls modified config files every 60 seconds to check for changes. If any of those files have changed, the logger config is modified on the fly. You can customize this interval by setting the monitorInterval attribute in the root element (check log4j 2 manual for further reference).

Making the HTTP Connector More Verbose

To debug projects that use the new HTTP connector you may find it useful to make the logging more verbose than usual and track all of the behavior of both the http-listener and http-request connectors on your project. To activate this mode, you must make the following addition to your log4j2.xml configuration file:


         
      
1
2
<AsyncLogger name="org.glassfish.grizzly" level="DEBUG"/>
<AsyncLogger name="org.asynchttpclient" level="DEBUG"/>

Controlling Logging from JMX

You can expose a manager’s logging configuration over JMX by configuring a log4j2 JMX agent in your Mule configuration file. See JMX Management for more information.

Request and Response Logging for SOAP

One of the most common requirements during development is to be able to log both request and response, raw, for web services calls, especially for SOAP calls.

To handle this:

  1. In Anypoint Studio, copy the cxf.xml file to src/main/resources for your project.

  2. Open the log4j2.xml file in src/main/resources and add the org.apache.cxf > INFO statement to the CXF section:

    
                
             
    1
    2
    3
    
    <!-- CXF is used heavily by Mule for web services -->
    <AsyncLogger name="org.apache.cxf" level="WARN"/>
    <AsyncLogger name="org.apache.cxf" level="INFO"/>
  3. Save your project.

Troubleshooting Logging

I don’t see any logging output

Set the log4j2.xml at the root of your classpath. For more information about configuring log4j2, see Apache’s website.

I reconfigured log4j2, but nothing happened

This happens because there is another log4j2.xml file on your classpath that is getting picked up before your modified one. To find out which configuration file log4j2 is using, add the following switch when starting Mule (or container startup script if you are embedding Mule):

-M-Dlog4j.debug=true

This parameter writes the log4j2 startup information, including the location of the configuration file being used, to stdout. You must remove that configuration file before your modified configuration can work.