Flexible Logging on the Fly
This blog is actually written by @anthony_defusco. It is the second of what he hopes to be a continuing series of quick tips and tricks for the beginner and intermediate Mule developer. Seasoned veterans of Mule development might also pick up a nugget or two of useful information as well. Part 1 can be found here.
If you write Mule applications and need to easily manage logging level, then read on brave developer: this “quick” tip is for you!
A Typical Use-case
While debugging a project we may want use the Logger component to dump the contents of the current payload to the log but not all of the time.
There are a number of ways to achieve this.
Starting from the out-of-the-box log Level setting of INFO, you temporarily mute the output to the log by changing the Logger component’s Level to a setting more verbose than INFO, i.e. DEBUG or TRACE.
Another technique is to temporarily mute the Logger by toggling it as a comment.
Yet another method is to leverage the Choice router technique, introduced in my first quick tip, to disable the Logger processor.
There is also the brute force method of either deleting the Logger processor or commenting out its XML to mute the output.
This method necessitates adding it again or toggling the comment off.
There are probably other methods to mute and unmute the output to the log, but like the methods shared above, they are compile-time modifications.
Wouldn’t it be great to flexibly manage the log level of a Mule application without needing to rebuild? How about, without needing to restart?
Well, you’re in luck!
You can do it without introducing any extra logic or message processors. Before diving deeper into the configuration details, you need to become acquainted with the Mule entity being used as an identifier.
Introducing app.name
The Mule runtime engine provides a number of predefined variables which refer to a variety of Mule Runtime engine objects. One such predefined variable, app, references the current application’s individual context within the running Mule Runtime engine. It has a number of useful fields such as encoding, name, registry, standalone, and workDir. The name field will be used to pair the Mule application’s Logger component with the Mule application. To ensure a proper pairing, you need to know what the value of the field app.name is.
Determining the value of app.name from a project within Anypoint Studio
Inside Anypoint Studio, app.name refers to the project’s name as it appears in the Package Explorer (see quick-tip-002 in the following screenshot)
and within the project’s .project file.
<?xml version="1.0" encoding="UTF-8"?>
<projectDescription>
<name>quick-tip-002</name>
<comment></comment>
<projects>
…
</projectDescription>Determining the value of app.name from a deployed application
From the perspective of an application deployed to a local or on-premise standalone Mule runtime, app.name refers to the deployed application’s folder name on the server. The value of app.name can also be extracted from the filename of the system-generated anchor file; it is the portion of the filename before “-anchor.txt”.
/apps$ ls -al
total 1drwxr-x--- 1 Administ 42949672 0 Jul 18 15:45 .dr-xr-x--- 1 Administ UsersGrp 0 Jul 18 14:23 ..drwxrwx--- 1 Administ UsersGrp 0 Jul 18 15:45 quick-tip-002-rwxrwx--- 1 Administ UsersGrp 77 Jul 18 15:53 quick-tip-
002-anchor.txt
Determining the value of app.name with Anypoint Runtime Manager
When using Anypoint Runtime Manager (ARM), app.name is the Name of that application as it is (or will be) specified to ARM:
ARM has naming conventions which must be adhered to. To ensure compatibility between local/on-premise and ARM deployments, it is recommended that the application name comply with ARM‘s requirements for the naming of a deployment:
Phew!
Still with me? Good. Now it starts to get interesting.
You can incorporate app.name into a strategy to flexibly manage the log level of a Mule application without needing to modify or rebuild it!
Preparation
All of the Logger components in a Mule application receive their direction from the application’s individual Log4J configuration file. This file is located in the project’s src/main/resources folder with the name log4j2.xml. When a new Mule application is created with Anypoint Studio, the default contents of the log4j2.xml file are similar to the following.
A few tweaks to the log4j2.xml file are needed before the magic can happen.
1. [Optional] Enable automatic logger configuration reloading by setting the monitorInterval attribute of the Configuration root tag at the top of the file. In the following example, a thread monitors for changes to the log4j2.xml file every ten seconds.
<?xml version="1.0" encoding="utf-8"?>
<Configuration monitorInterval="10">
…This tweak enables you to make real-time logger configuration changes to a running on-premise or local Mule application, which takes effect without an application re-start. Note: You need write access to the deployed applications within the file system of the Mule runtime server.
2. [Optional] Create a Console appender for controlling the output to the Anypoint Studio console log, configure the pattern of the PatternLayout tag to your preference, and then reference the new appender in the AsyncRoot tag.
In the above example, the output of the logger has been simplified to include only the timestamp, thread information, and message.
3. Create a new asynchronous logger for the application and reference the defined appenders. (Don’t forget to reference the “Console” appender if you created it in optional step 2.) The name attribute of the AsyncLogger tag must match the value of the application/project name (i.e. the value of the app.name field).
Notice that the additivity attribute of the AsyncLogger tag is set to false to prevent unnecessary extra copies of our log messages being created by the root logger. The level attribute may be set to any starting value; here it has an initial value of “OFF” to start up our logger in a muted state, the preferred state for production.
If the deployment name of the application ever needs to change, then the name attribute of our AsyncLogger is the only place that needs to be updated. You’ll see why that is the case in the next section.
Logger Category FTW!
Now you can finally focus on the magic ingredient, Category, to mute or unmute logger output on demand!
Here you make use of app.name once again. Set the value of Category to be the Spring property placeholder expression ${app.name}. The value of the Level field can be anything, as you will see shortly, but a value of DEBUG is a good choice.
And this is what it would look like configured in the application XML file.
By using ${app.name} as the value of the Category setting for the Logger component, you have an identifier for specifying a logger configuration that is fairly easy to pair with a specific application.
NOTE: The Logger component’s Category setting is not currently compatible with DataWeave expressions. A DataWeave expression like #[Mule::p(“app.name”)] would actually be interpreted as a String value instead, so that is why it is necessary to use the Spring property placeholder here.
To Mute or not to Mute
As a review, the Logger component and application must be paired by using ${app.name} in the Category field of the component and the specific application name in the log4j2.xml file.
Since log4j logging levels are ordered according to their corresponding integer constant values (see Logger Level Hierarchy… chart below), the value assigned to the AsyncLogger in the log4j2.xml file must have a verbosity level that is greater than or equal to the corresponding verbosity level assigned to the Level of the Logger component in order for logger messages to be output.
Logger Level Hierarchy of Decreasing Verbosity
Regardless of the Level setting in the Logger component, a value of ALL will unmute the Logger while a value of OFF will completely mute the Logger.
If write access to the deployed application’s log4j2.xml file on the server is possible and the monitorInterval attribute of the Configuration tag was previously set in the log4j2.xml file, then real-time changes to the logger settings will take effect without an application restart.
With respect to Mule applications managed with ARM, the process is nearly the same as for manually managed applications, except that real-time changes to the log level are done in the managed application Settings → Logging page in Runtime Manager:
Conclusion
There you have it: a technique for flexibly managing the log level of a Mule application while it is running.
A requirement for using the described technique is that the application must not use the Category setting for another purpose.
Be sure to check out my next Mule development quick tip in the series when it drops.
Ciao for now.
