In this article we present CoralLog, a powerful, ultra-low-latency and asynchronous logging library with a very intuitive and non-intrusive API. First we show you how you can use CoralLog for level logging, in other words, to log status messages from your application using the log levels available such as Debug, Trace, Error, etc. Then we show in a follow up article how you can use CoralLog for event sourcing, in other words, to write any kind of message (i.e. data) to a file without adding latency or variance to the critical thread doing the logging. If you are interested in the article with the performance numbers of CoralLog you can check here.
Level Logging
Let’s start with a CoralLog Hello World:
// this static import is all you need to start using CoralLog:
import static com.coralblocks.corallog.Log.*;
// then, anywhere in your code you can write:
Warn.log("Hello World!");
Info.log("Hello Again!");
When you execute the code above you see in the console:
13:54:21.322715-WARN Hello World! 13:54:21.322816-INFO Hello Again!
By default, CoralLog logs to the console (i.e. standard output) but you can easily change it to log to a file instead, as below:
// anywhere in your code, you can write:
// (or pass -DlogFile=true in the JVM command-line)
Log.setFile(true);
// now everything goes by default to a file:
Error.log("Hello World!");
Info.log("Hello Again!");
Now if you look in your current directory, you will find a file named corallog-levels.log with the contents:
LOG OPENED - 16/05/2018 05:02:42.237 05:02:42.238762-ERROR Hello World! 05:02:42.238762-INFO Hello Again!
To change the name of the file, you can do:
// (or pass -DlogLevelLoggerFilename=all-level-logging.log in the JVM command-line)
Log.setLevelLoggerFilename("all-level-logging.log");
To change the directory in where you want the log file, you can do:
// anytime, anywhere in you code, you can write:
// (or pass -DlogDir=/Users/coralblocks/ in the JVM command-line)
Log.setDir("/Users/coralblocks/");
// now the log below goes to /Users/coralblocks/corallog-levels.log
Error.log("Hello World!");
Logging is easy and you can choose among the flavors below:
// CoralLog varargs make it convenient to build your
// messages without the varargs array allocation overhead:
Warn.log("This is a log message!", "user=", "foo", "age=", 21);
Outputs:
14:40:41.589516 This is a log message! user=foo age=21
NOTE: With CoralLogs, you can use up to 16 objects in a varargs method call without producing any garbage, in other words, without causing the JVM to allocate a new object array to be passed to the method call.
When using varargs, the CoralLog default rule is to separate each object with a space character. The exception is when you have a string ending in ‘=’. Instead of “user= foo” it does not use the space and prints “user=foo”. If you don’t like this trick you can call the method below:
// do not suppress the space in between object after an '=': // default is true, to NOT have the space after an '=' sign // (or pass -DlogNoSpaceAfterEqualSign=false in the JVM command-line) Log.setNoSpaceAfterEqualSign(false); // and you can also suppress the space completely with: // default is false, to have the space between objects // (or pass -DlogNoSpaceBetweenObjects=true in the JVM command-line) Log.setNoSpaceBetweenObjects(true);
If you prefer, you can also use placeholders when constructing the log message, as below:
Warn.log("This is a log message! user={} age={}", "foo", 21);
Of course you can also take control of the whole message by preparing your own StringBuilder, CharSequence, ByteBuffer or byte[] and logging it as below:
StringBuilder sb = new StringBuilder(1024); // cache and re-use this instance
sb.setLength(0);
sb.append("This is a log message!");
sb.append(" user=").append("foo");
sb.append(" age=").append(21);
Warn.log(sb);
Avoiding Autoboxing
One of the most important features of CoralLog is its zero garbage creation, in other words, you can log as much as you want without producing any (i.e. zero) garbage. The goal is to eliminate any GC overhead in the system. If you pass any primitive value (i.e. integer, long, boolean, etc.) to a log call, autoboxing will occur and garbage will be created under the hood by the JVM. CoralLog provides an easy way to escape autoboxing, as you can see below:
// use the to_sb method to translate a primitive into a StringBuilder:
Warn.log("This is a log message!", "user=", "foo", "age=", to_sb(21));
By using the method to_sb, you can translate on-the-fly a primitive value into a StringBuilder so no autoboxing occurs. You should know that whenever you write a primitive value to a StringBuilder no garbage is created, so another way to escape autoboxing is to write the whole message to a StringBuilder as the previous example showed:
StringBuilder sb = new StringBuilder(1024); // cache and re-use this instance
sb.setLength(0);
sb.append("This is a log message!");
sb.append(" user=").append("foo");
sb.append(" age=").append(21); // no garbage is created when you write 21
Warn.log(sb);
The difference is that the to_sb method only writes the part of the message (i.e. the primitive values) that would cause autoboxing to a StringBuilder, instead of the whole message.
Log Levels and Colors
When logging to the console (i.e. standard output), you can use colors to separate among the log levels. Linux/Unix terminals usually support this great feature, so to turn it on you can do:
// call that anytime, anywhere in your code: // (default is false because some terminals (win) do not support colors) // (or pass -DlogColors=true in the JVM command-line) Log.setColors(true);
If you prefer, you can also change these colors with the code below:
// change the Warn level to green: // (or you can pass -DlogWarnColor=32 in the JVM command-line) Warn.setColor(32);
The available colors are:
30 - Black 31 - Red 32 - Green 33 - Yellow 34 - Blue 35 - Purple 36 - Cyan 37 - White
Enabling/Disabling Log Levels
CoralLog log levels, in order, are: Debug, Trace, Info, Event, Warn, Error, Alert, Critical and Emergency. To log everything on and above the Trace level, you can do:
Trace.log("Can you see me?");
// log Trace and anything above Trace:
// (default is Info)
// (you can also pass -logLevel=trace in the JVM command-line)
Log.setLevel(Trace);
Trace.log("Now you can!");
In addition to setting the log level of the whole application, you can enable and disable individual logs, as the example below shows:
Warn.enable(true); // no matter what the level is, it will be logged Warn.enable(false); // not matter what the level is, it will NOT be logged Warn.enable(null); // go by the current log level as usual...
Although the log method will not log anything if the level is not enabled, you can use the conditional below to avoid having to build a message and making the log call:
if (Trace.isEnabled()) {
Trace.log("Tracing something!");
}
Asynchronous Logging
By default, CoralLog is asynchronous, in other words, all file i/o is done in another thread so the overhead in the critical thread doing the logging is minimum. The log messages are transferred to the writing thread through a disruptor queue. If for some reason you want to turn off asynchronous mode, you can do:
// turn off asynchronous mode // (default is true) // (or pass -DlogAsynchronous=false in the JVM command-line) Log.setAsynchronous(false);
Closing the Asynchronous Thread
The asynchronous thread (the writer thread doing the actual file i/o), is not a Java daemon thread, in other words, it will prevent the JVM from exiting unless this thread is properly terminated. That’s on purpose because we do not want this thread to be killed by the JVM on exit while it is still draining the queue. Therefore, if you want to graciously exit the JVM, you can use the method below:
// block, drain the queue (all loggers), die and return... AsyncThread.drainDieAndWait();
You can also drain all loggers and return like below:
// block, drain the queue (all loggers) and return... AsyncThread.drainAndWait();
There is also a non-blocking version that returns immediately:
// returns immediately and signal the async thread to // drain and die as soon as it can AsyncThread.drainAndDie();
NOTE: The cleanest way to exit the JVM is to close all your loggers and issue a AsyncThread.drainDieAndWait().
Memory Mapped Files
By default, CoraLog uses a FileChannel to log messages to disk. For maximum throughput you should use a memory-mapped file instead. The reason FileChannel is the default, and not memory-mapped files, is that for level logging you are usually not worried about throughput since you will probably not be logging millions of status messages per second. Now latency is always important, and for that it does not matter if you are using a FileChannel or a memory-mapped file because CoralLog is asynchronous.
One disadvantage of memory-mapped files is that it can be hard to inspect or tail the file while logging is taking place. That’s because it is the OS that is making the decision of when to transfer data from memory to disk. Also a big chunk of memory (through a MappedByteBuffer) and file space (filled with blank spaces) must be pre-allocated. When the file fills up, in other words, when all the blank space has been overwritten with log data, the file is expanded with another pre-allocated chunk of the same size, so the file grows in chunks which fools the Linux tail command. Notice that CoralLog always truncates the file when rolling to a new chunk and when closing the logger, so no blank space is left in the file.
These disadvantages are very small when compared to the gains in throughput that memory-mapped files can deliver. For level logging you probably won’t care for throughput (just for latency), but for event sourcing you surely will. That’s why for event sourcing, memory-mapped files are the default.
If you want, you can control memory-mapped files in CoralLog for level logging with the following code:
// turn on memory-mapped files for level logging
// (default is false)
// (or pass -DlogMemoryMappedFile=true in the JVM command-line)
Log.setMemoryMappedFile(true);
// to change the memory-mapped buffer size (page size or chunk size as we talked above)
// (default is 50Mb)
// (or pass -DlogMemoryMappedBufferSize=100m)
Log.setMemoryMappedBufferSize("100m");
Additional Features
CoralLog comes with many more features. Below we list some of them:
- Encoders: so you don’t create any garbage with calls to
toString(), in other words, the encoder will know how to write the object to aByteBufferwithout creating any garbage. CoralLog comes out-of-the-box with 5 encoders: one forCharSequence(String,StringBuilder, etc.), one for byte and char arrays, one for null objects, one forByteBufferand one forThrowable. These encoders are included by default and you can see them by calling Log.getEncoders(). You can also create and add your own encoders. - Interceptors: so you can intercept the
ByteBuffercontaining the log message and do whatever you want, such as send to syslog, write to a database or modify the message in any way you want before it makes it to the file (or console). - Debugging: you can also choose to print class names with line numbers in your log messages for debugging purposes. You can also choose to filter the log messages by package and class names so you can remove the noise and see only what you need when debugging.
- Rolling a log file: at any time you can call the
roll()method on any logger (Ex:Warn.roll()) to roll the log file. The current log file is renamed with the date in the filename and a fresh new one (i.e. WARN.log) is created. - SLF4J: fully compatible with slf4j (http://www.slf4j.org)
