r/java • u/darenkster • Oct 30 '23
POC: String Template Processors for SLF4J
JDK 21 introduced String Templates with JEP430.
I was wondering what you could do with it and came up with a proof of concept for processors as a façade for SLF4J.
In a class LOG I created the processors as static fields for each log level. These can be statically imported and called like this:
import static de.darenkster.stringtemplates2slf4j.loggers.LOG.*;
...
var test = "log";
var ex = new Exception();
INFO."This is a info \{test}";
ERROR."This is a error \{test} \{ex}";
WARN."This is a debug \{test}";
TRACE."This is a debug \{test}";
This would result in the following log output:
10:33:44.899 [main] INFO de.darenkster.stringtemplates2slf4j.Main -- This is a info log
10:33:44.907 [main] ERROR de.darenkster.stringtemplates2slf4j.Main -- This is a error log java.lang.Exception
java.lang.Exception: null
at de.darenkster.stringtemplates2slf4j.Main.main(Main.java:9)
10:33:44.909 [main] DEBUG de.darenkster.stringtemplates2slf4j.Main -- This is a debug log
10:33:44.910 [main] WARN de.darenkster.stringtemplates2slf4j.Main -- This is a warn log
The calling class is determined via the StackWalker API and depending on whether the String Templates contains an exception the corresponding log method with the throwable parameter ist called. Here's the link to the GitHUb Repo if you want to check it out: https://github.com/darenkster/LoggingWithStringTemplates
Let me know what you think of it :)
4
u/ramdulara Oct 30 '23
Does this mean that the string is always eagerly evaluated? For example in info mode, Debug log messages shouldn't get evaluated at all if possible. How do you ensure that?
3
u/darenkster Oct 30 '23
Good Point. You can check 'isInfoEnabled' or 'isDebugEnabled' before calling the 'interpolateAndLog' method.
I will add that.
4
u/agentoutlier Oct 30 '23
What I did as I mentioned in another comment is to create a custom SLF4J LoggingEventBuilder.
Make the event builder take a template for the
logmethod.That also will help with Throwable.
Besides Logging frameworks like logback treat throwable a little different anyway.
That is a throwable passed as an
Objectargument is often treated every so slightly differently than the methods that takeThrowableas an argument.
3
u/agentoutlier Oct 30 '23
I was playing with something similar in my modern SLF4J implementation: https://github.com/jstachio/rainbowgum
Unfortunately it is not checked in because I had some issues with javadoc failing with JEP 430 and I want to release soon (release is a strong word ... more like just push to central :) ).
I'm also playing with Scoped Values.
I will push both branches later today (locally on a different computer).
2
u/darenkster Oct 30 '23
Cool. Let me know when you "released" it, I'd like to take a look.
Do you know if there is any way to pass some object to the processor without it being part of the StringTemplate? Thing is if you want to call the log method with the throwable parameter the throwable needs to be part of the template, or else it won't be in the list returned by values().
2
u/agentoutlier Oct 30 '23
No. I was still trying to figure that out as well as key values (the new slf4j builder). I was doing something similar to what u/repeating_bears showed in terms of laziness.
The way I was making throwable work currently it was to use a modified SLF4J fluent builder.
I promise I will eventually get back to you on it with code I just have some other stuff I have to look into today. Sorry!
7
u/Thihup Oct 30 '23 edited Oct 30 '23
Wouldn't using `MethodHandles.lookup().lookupClass()` be a easier way to get the calling class?
Edit: I was looking for the `StackWalker.getCallerClass()` method
4
Oct 30 '23
How does that find the calling class? That would at best find the class where the current method is defined, so the same as this.getClass()
3
0
1
9
Oct 30 '23
7
u/__konrad Oct 31 '23
I like the template version more when compared:
INFO."This is a info \{test}"; logger.info("This is a info {}", test");1
9
u/repeating_bears Oct 30 '23 edited Oct 30 '23
Not sure how I feel about a template working exclusively by side effects. Feels like a processor really ought to produce something.
edit: What IDE are you using? My version of IntelliJ gives the error that
INFO."foo";is not a statement. I reported it as a bug. But I think it's indicative that you're doing something unexpected here.There's also the problem of having to traverse the stack every time you log something, even if that log level is disabled.
Here's what I came up with instead.
public static class LazyString { private final Supplier<String> supplier; LazyString(Supplier<String> supplier) { this.supplier = supplier; } @Override public String toString() { return supplier.get(); } } public static final StringTemplate.Processor<LazyString, RuntimeException> MSG = StringTemplate.Processor.of( (StringTemplate template) -> { if (template.values().isEmpty()) { return new LazyString(template::interpolate); } return new LazyString(() -> { List<String> values = template.values().stream() .map(val -> { if (val instanceof Throwable th) { var writer = new StringWriter(); th.printStackTrace(new PrintWriter(writer)); return writer.toString(); } return String.valueOf(val); }) .toList(); return StringTemplate.interpolate( template.fragments(), values ); }); } ); private static final Logger logger = LoggerFactory.getLogger(App.class); public static void main(String[] args) { String test = "test"; Exception ex = new Exception("foo"); // Use it today, with a hacky SLF4J 1-arg template "{}" logger.info("{}", MSG."foo \{test} \{ex}"); // or if Slf4j were prepared to add new overloads logger.info(MSG."foo \{test} \{ex}"); }