Spring Shell is a fantastic piece of kit for building commandline applications.
In this post I share some cool ways we can integrate slf4j and as a result, we can avoid peppering our code with System.out.println(), avoid untidy string concatenation by making use of slf4j’s {} {} string interpolation, all the while retaining colorization with a neat abstraction called markers to avoid peppering our code with ANSI-COLOR constants.
When I was building my application, all the tutorials that explained how to write back to the user did so using System.out.println(). At first I thought this was maybe a stop-gap, and that there was some other way in the library to write back to the user. Writing to stdout felt wrong, we were always taught not to do it, and that if we wanted to log something, to use a logging framework. Right?
Well I guess technically we’re not logging, we’re talking to the user. Even so, there are other reasons not to use stdout. For a start, how do you test it? How do you assert what was emitted to the user? I don’t know but it’s probably a royal pain in a unit test to intercept stdout and check what’s being written and then forward it on.
On top of that, it’s just so ugly, sure you could wrap it up in a method and call the method instead but it still felt like there’s something dirty about writing to stdout directly.
For sure this is a command line application and ultimately something’s got to write it to stdout, but I just don’t feel that it should be done at the application level.
So what were all the reasons for not liking stdout?
- It’s not easily tested in junits.
- Direct inline usage would result in peppering the code with
System.out.println("")which is rather verbose. - It has this ugly concatenation syntax and would require a StringFormatter to wrap every string which is not very pretty either.
- How would I colorize things? ANSI.color everywhere?
- It just feels nasty.
- If I wanted to log a response, I would have to have an additional log statement for each print statement.
- You can’t easily make the output to stdout less verbose via configuration.
Let us consider slf4j and how it might solve the above issues.
- Instead of duplicating output in stdout and logger, just log once and set an additional STDOUT appender.
- An slf4j logged could be injected in unit tests, better yet an object that wraps this could too.
logger.info()is slightly shorter thanSystem.out.println()- Invoking a logger feels more natural.
- Setting a logger level could make the output more or less verbose as necessary.
- Colorization can be done with Markers (we’ll see shortly).
We can see the slf4j solves some of the problems, one of the outstanding problems is ensuring that if we change our design, we won’t have to change everything in our code. It looks like we need a flexible abstraction that is clear enough to be understood but terse enough to not clutter up our code. An abstraction that can hide the implementation details of how we use slf4j to colorize output and be injected into our classes.
Lets start with our abstraction, we create a class called Output
- Try and mimic the slf4j interface
- Create a method of each color we might use.
- Create a generic method to allow us to extend.
- Take varargs that can be interpolated in the message.
public interface Out {
void green(String message, Object[] loggables);
void magenta(String message, Object[] loggables);
void white(String message, Object[] loggables);
void color(OuputColor color, String message, Object[] loggables);
Out info();
void info(String message, Object[] loggables);
Out debug();
void debug(String message, Object[] loggables);
Out warn();
void warn(String message, Object[] loggables);
Out error();
void error(String message, Object[] loggables);
Out level(LogLevel logLevel);
}
We would set the default log level to be something sensible like info.
Here are a few examples
private static final Out out = SimpleOut.getOut(MyClass.class);
//output green at default info level
out.green("How many words in this green info text? {}", 7);
//warning without specifying color (yellow by default)
out.warn("This warning would be in yellow by default");
//warning level message but in red.
out.warn().red("However this warning would be in red");
//custom color at info level
out.color(customcolor(), "message {} {}", param1, param2);
//custom pink color at error level
out.error().color(pink(), "message {} {}", param1, param2);
//custom level with custom color for the ultimate cheese on toast.
out.level(trace()).color(pink(), "message {} {}", param1, param2);
We could implement these classes as follows:
public class SimpleOut implements Out {
public enum Color {
RED, YELLOW
}
private final Class<?> clazz;
private final LogLevel logLevel;
public static Out getOut(Class<?> clazz) {
return new SimpleOut(clazz, INFO);
}
public static Out getOut(Class<?> clazz, Level logLevel) {
return new SimpleOut(clazz, logLevel);
}
public SimpleOut(Clazz<?> clazz, Level logLevel) {
this.clazz = clazz;
this.logLevel = logLevel;
}
public void green(String msg, Object[] args) {
log(GREEN, msg, args);
}
public error() {
return new SimpleOut(clazz, ERROR);
}
public void log(Color color, String msg, Object args[]) {
if (level.equals(INFO)) {
logger.info(MarkerFactory.getMarker(Color.GREEN.toString()), msg, args);
} else if (level.equals(WARN)) {
//...
} // error & debug too
}
}
Custom Highlighter
public class CustomColorConverter extends HighlightingCompositeConverter {
@Override
protected String getForegroundColorCode(ILoggingEvent e) {
if (e.getMarker() != null) {
if (e.getMarker().contains(red())) {
return RED_FG;
} else if (e.getMarker().contains(yellow())) {
return YELLOW_FG;
}
//etc
}
return WHITE_FG;
}
}
The log configuration in logback would look something like this:
<?xml version="1.0" encoding="UTF-8" ?>
<configuration debug="false">
<include resource="org/springframework/boot/logging/logback/defaults.xml" />
<conversionRule conversionWord="highlight"
converterClass="uk.co.solong.projectname.CustomColorConverter" />
<statusListener class="ch.qos.logback.core.status.NopStatusListener" />
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>INFO</level>
</filter>
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<pattern>%highlight(%msg%n)</pattern>
</encoder>
</appender>
<!-- this logger writes all classes within the co.uk.solong.project package space to STDOUT but also to a file based log -->
<logger name="co.uk.solong.projectname" level="INFO" additivity="false">
<appender-ref ref="FILE-AUDIT" />
<appender-ref ref="STDOUT" />
</logger>
<root>
<level value="INFO" />
<appender-ref ref="FILE-AUDIT" />
</root>
</configuration>
The log file has a logger which binds to the package name co.uk.solong.projectname so that only the log statements from classes contained within this package namespace will be fed to the appenders.
I’ve only shown one appender here, but the other is the file-audit you can configure it how you like.
Note that the file-audit is bound to the root in order to ensure that everything is logged in the log-file. The STDOUT is bound to logger to reduce noise from 3rd party libraries.
We include the springframework defaults for some reason I can’t remember. The conversionRule exists to process the highlight() function by using the CustomColorConverter. This is the main highlighting responsibility. The msg section is just the regular msg string without any timestamps attached, this is different to how you would normally format a log line.
A complete implementation of this blog post will be made available in a library I am wroting called Clog (as in Color Log, not the Danish footware) Unlike the Danish clog, this library, compared to using stdout, is hopefully comfortable to use and looks good.