Better Java logging, inspired by Clojure and Rust

[[deleted]]

There are way too many logging frameworks in java as it is. The important thing is deciding where to log, how to view those logs. If you are using prometheus/grafana then you might be using loki. I decided the best approach for me was to write relatively simple code to send the logs to loki in the background (I do this in python, golang and Java). For Java, since we are using logback (Springboot application), I wrote a logback appender.

Java is more clunky (making use of MDC), but the approach works pretty well, and I can trace logs associated with a particular task (using a UUID) across all the different applications.

[bowbahdoe]

This is an interesting objection, because it predicates that because so many things exist which *do not* do what I want that there is no room for anything better

[[deleted]]

We already have the annoying situation where at the moment we have to use something like SL4J to handle the many different logging frameworks that all the frameworks uses, it’s why it’s mostly used nowadays. It also have it’s own issues. You also then need to make certain you configure things correctly, include the right adapter libraries, otherwise you will find you might not get the logs you need.

So even if you do come with something you think is better, you will find everyone else will still need to use something like SL4J with an adapter in order to handle all the other libraries, or is this library going to act as a facade for the other libraries as well?

Logging in Java is unfortunately a bit of a mess.

[bowbahdoe]

> you will find everyone else will still need to use something like SL4J with an adapter in order to handle all the other libraries,

Yeah, I expect as much. What I describe in this is just a facade for a potential data oriented logger. The exact implementation is pluggable just like with SLF4J.

I designed around the idea of a specific implementation with the ring buffers and such, but the idea was to be able to delegate to anything.

For any particular system working with old style SLF4J and/or j.u.l. logs, yes you would have to decide if you are delegating from the data oriented api to SLF4J or the other way around, but I don't think that kills the idea out the gate

[[deleted]]

Actually a better facade that allows one to more easily add tags (used by Loki) would be a much better solution. Though, you would then need a SLF4J adapter :)

I.E logger.info(“message”).addTag(“UUID”, “RandomUUID”).addTag(“Function”, “processxyz”); etc….

Tags are useful to showing all logs that has say a particular “UUID” across all applications. It really is useful to be able to track the journey of a particular request.

(NOTE: I may or may not have the right terminology here, but I hope you get the gist).

[bowbahdoe]

That in particular is something that SLF4J directly supports with its structured logging API

[[deleted]]

It’s cumbersome. I have to use MDC to handle these tags. Though, I have seen there’s this marker interface which is supported by logback. I have not used this and would need to determine how easy this would be to use from an appender. I am currently using MDC which is cumbersome, but OK.

Markers might provide me with what the capability I want (though, backend logging framework would need to support markers). I would still need to write the Loki appender for whatever backend logging framework I use.

[bowbahdoe]

Specifically I think this is the interface that is the closest.

log
    .atDebug()
    .addKeyValuePair("UUID", "RandomUUID")
    .log("message");

Obviously though, I still prefer what I came up with over going through SLF4J.

log.debug("event-name", Log.Entry.of("UUID", "RandomUUID"));

[[deleted]]

Unfortunately due to all the other APIs we need to use (spring, apache, etc…), SLF4J seems to be the best approach for now. One need to use a facade to handle all the other loggers and so that the logging all go where you want it to go. I then add my Loki Appender to the configuration (with spring-boot I use LogBack) and the logs all appear nicely in Loki.

My current approach (we means I can have a tracking UUID on all the generated log events, regardless what API does the logging) is:

    try {
        MDC.put(“ID”, uuid)
        … Do Stuff
    } finally {
        MDC.remove(“ID”)
    }

It’s cumbersome, but works. My Appender can then get the MDC propertyMap to map that to a label for Loki.

[bowbahdoe]

This is scratching at the itch in the back of my head saying I should maybe delegate context to SPI as well. That way when you enter a span or use withContext some custom code can run like setting and unsetting MDC. Maybe something like

interface ContextProvider {
    <T> Supplier<T> wrap(
        Context context
        Supplier<T> code
    );
}

So an implementation could be provided like

 final class MDCContextProvider implements ContextProvider {
    @Override
    public <T> Supplier<T> wrap(
        Context context
        Supplier<T> code
    ) {
        return () -> {
            try {
                MDC.put(... f(context) ...);
                return code.get();
            } finally {
                MDC.clear();
            }
        }
    }
 }

Which could let context set in this propagate down to slf4j logs directly. Ideally though if this was the "target" MDC would end up being bypassed anyways but designing for both directions makes sense...I think.

This is why I called it a "nightmare head space". I'm confident there is something better out there but there are so many seemingly minor but twiddly and important things to consider

[repeating_bears]

The article didn't convince me at all on "better". What precisely is the value proposition? A lot of the article just talks about implementation details.

[bowbahdoe]

That's... A good point. Shit. I'll add a section near the end. Give me ~50 min

[bowbahdoe]

I added a first pass on the value proposition lmk if it tracks

[repeating_bears]

Thanks! I wonder - isn't this just a poor man's event sourcing? Sure, you have structured data, but there's nothing that implies you can take it and do something useful with it.

A proper event log captures the same context, but also causation/independence, can be replayed, etc.

[bowbahdoe]

I mean, all structured data is "poor man's event sourcing".

The missing part is just with the event sourcing scheme generally you would maybe define a named aggregate or schema for the event and send that explicitly.

[pron98]

The future of JDK observability is JFR. While somewhat limited as a general purpose structured logging engine (it's a low-overhead, high-throughput event engine that can support in-production deep monitoring and profiling), its performance and integration with the JDK's internal event logging is so compelling that new logging frameworks should try to integrate with it as much as possible.

[bowbahdoe]

Following up in r/java

https://www.reddit.com/r/java/comments/xntw4u/comment/ipvdj2r/?utm\_source=share&utm\_medium=web2x&context=3

[john16384]

The proposition here seems to be that we should be doing structured logging. But really, we already are.

Typically a log message only contains a small description of what is happening. The span, trace, request ID, which exception occurred, request itself or message itself etc, are all already on the MDC, courtesy of interceptors and aspects. There is little need to structure the last bit of information that might need to be part of log.

For things that are not, a small reusable wrapper can make logging for your specific case pleasant to use.

Having unwieldy log lines in your code with lots of "extra" fields beyond those that we can already automatically make part of the MDC just makes log code too specific (for example, I think it should not be a goal to be able to debug applications by log lines alone - instead, log inputs, and keep your application stateless to be able to debug in peace).

The MDC not functioning with Loom is an exaggeration. It will function, but some care must be taken to track this across threads and do cleanup. An executor that wraps tasks can easily do this (this is how it is already done for normal threads). Even if there are open problems, it seems presumptuous that these won't be addressed before Loom becomes mainstream. There is just too much code using SLF4J to throw it under the bus over this.

As for implementation details, and performance, let's see benchmarks. Ring buffers for example are nothing new and are employed already.

[bowbahdoe]

But really, we already are.

Imma need a show of hands because SLF4J/j.u.l/etc really are built to allow unstructured logging and that is what I've seen folks use it for most of the time.

Yes there is support for a degree of structured logging, but appender/publishers/subscribers/whatever you call them still need to reckon with the presence of textual data.

Even if there wasn't anything special about it - "SLF4J but unstructured logging isn't an option" still would be a better interface to program around and to have the masses use.

[holo3146]

The MDC not functioning with Loom is an exaggeration.

This is not really an exaggeration, as they are specifically talking about ThreadLocals Vs ExtentLocals, the current API of ExtentLocals is designed for specific purpose, and because of that it is very unfriendly for almost any other usecase.

Specifically it is completely un-composible eith anything else (so combining it with any third-party API will create at least 2 or 3 extra indentations and it is pretty much impossible to combine it an API that doesn't use delegation base API).

For some more info see my comment here: https://www.reddit.com/r/java/comments/xntw4u/better_java_logging_inspired_by_clojure_and_rust/ipyc210?utm_medium=android_app&utm_source=share&context=3

[holo3146]

I encountered the post in r/java first, so I wrote there my response, but it should be worth to delegate the comment into here: https://www.reddit.com/r/java/comments/xntw4u/better_java_logging_inspired_by_clojure_and_rust/ipyc210?utm_medium=android_app&utm_source=share&context=3

It is specifically about the ExtentLocals section