Demystifying Log Category (turning logs on or off) in MuleSoft
Logging is an integral part of our development activities. It helps us to troubleshoot, draw nuanced insights, review historical data for auditing — an application without logging is just inconceivable!
The concept of message logging is generally considered to be indispensable for a software application. With respect to the implementation of a sensible logging strategy, the consensus is to remain judicious in the way we log, so that we don’t overburden the application and its associated resources as we log our messages.
Strategies behind logging judiciously
- LOG LEVELS — Pay meticulous care to the log levels you are using. Unless you are troubleshooting an issue, do not overuse the DEBUG log level.
- LOG CATEGORY — By introducing log categories into your application, you may segregate your log messages based upon the specific category which they serve. For example, you might use a log category to route log messages based on your own descriptor, or you might even align each of the log levels each with a specific category.
- ASYNCHRONOUS LOGGING — To reduce CPU overhead, it is always advised to use asynchronous threads to do your logging, so that your application is not waiting for CPU time while a log message is being written.
LOG LEVELS
Log levels are a very popular aspect in every programming language you might come across. As numbered here (lowest to highest), we have the following log levels which follow a broad hierarchy of chattiness/verbosity:
- ERROR — Indicates that a required piece of logic could not be executed successfully and is considered to be a failure with respect to technical or business requirements. This situation requires immediate attention and should be resolved in a short time.
- WARN — Indicates a potential issue which does not stop the program from fulfilling its runtime requirements nor does it require immediate attention.
- INFO — Provides small amounts of information which can be used for metrics and alerting. This may indicate the progress of a running process or the status of a completed process. The information logged using the INFO log is usually informative and does not require any follow-up.
- DEBUG — Gives diagnostic information in a highly detailed and verbose manner which may be useful for solving issues via close introspection into a run. The information provided may include actual business values and other run details. Unless troubleshooting, this log level should not normally be used.
- TRACE — Captures all the details about the behavior of the application. Used for mostly diagnostic purposes, it is finer and more granular than DEBUG log level. This log level may be used in situations where you need to see what happened in your application or what happened in the third-party libraries being used.
LOG CATEGORY
This blog is mostly centered around the context of category logging and attempts to explain how you can leverage it to gain more control over what you log and what you do not log.
Psst! There is a boolean switch on your log categories which you can use to turn your logs “on” or “off” from outside your application, without redeploying a new application jar.
The Proof is in the Pudding
To demonstrate the concept of category logging, I have created a very simple application which simply logs a hardcoded payload. What I want you to take note of is the “Category” parameter in my Logger components, “start-log” and “end-log”. I have made up two fictitious categories for my two loggers: “com.org.test-log-category” and “com.org.test-log-category.implementation-flow”
Now let’s take a look at their corresponding configuration in the log4j2.xml file, where all the magic unfolds! The following snippet is from my <Loggers> section of the XML, where I have added the two AsyncLogger configurations to recognize my two newly introduced categories:
Notice in the snippet above the configuration of a special attribute called additivity. This subtle boolean attribute of the AsyncLogger tag has the capability to turn your entire logs “ON” or “OFF” — for that entire category!
It’s a mind-blowing epiphany!
Test Scenario 1
In this scenario, I want only the start-log (with category value com.org.test-log-category) to display its contents, so I have set the additivity flag to the value of the system property, booleanAppLog, which is defined to be “true”, and for the other logger with category value com.org.test-log-category.implementation-flow, I have set the additivity flag to the value of the system property, booleanAppFlowLog, which is defined to be “false”.
As per my whim, I have the following setup in my Runtime Manager properties tab to turn my category logging on or off:
After submitting the following GET request from Postman …
it can be seen below that only the “Starting…” log messages appear in the Runtime Manager application log as well as in my Datadog:
The “Starting …” log message is the only one which appeared in the log file, despite another log message “Ending …” being defined in the flow. The “Ending …” log message was completely turned off by leveraging the combined capabilities of the Category attribute and the additivity attribute of the AsyncLogger tag in the log4j2.xml file.
Test Scenario 2
For this next scenario, I want both the “Starting …” log message (assigned to the category com.org.test-log-category) as well as the “Ending …” log message (assigned to the category com.org.test-log-category.implementation-flow) to be displayed. To make this happen, I have set the additivity flags of both their categories (booleanAppLog and booleanAppFlowLog, respectively) to “true”:
After resubmitting with Postman the same GET request from earlier …
it can be seen that the “Starting …” and “Ending ...” log messages each appear in the Runtime Manager application log as well as in my Datadog:
This time my application produced both the “Starting …” and “Ending …” log messages as was desired. By leveraging the power of the Category attribute combined with the magical additivity attribute in the log4j2.xml file’s AsyncLogger tag (using property values set in the Runtime Manager properties tab), I was able to effectively control which log messages were produced by my application.
Closing Thoughts
This methodology can serve as an effective way to eliminate those log messages which are no longer necessary, or which may overwhelm the underlying infrastructure, perhaps due to some sudden increase in volume of incoming requests. By externalizing the additivity attribute and setting it to true or false, such situations can be handled quickly and seamlessly.
That’s all for this blog folks! Hope you learned a little thing or two from this quirky tinkering of mine. Happy Logging!
References:
- Apache Log4j Configuration Strategy — https://logging.apache.org/log4j/2.x/manual/configuration.html#Additivity
