[slf4j-dev] Proposal for SLF4J 2.0 Logger API

[Remko Popma]

On Wed, Dec 18, 2019 at 4:36 AM Ceki <ceki at qos.ch> wrote:
>
> Hi Remko,
>
> Response inline.
>
> On 17.12.2019 11:51, Remko Popma wrote:
> > Hi Ceki,
> >
> > Sorry for raising this via the wrong channel initially.
>
> No problem at all.
>
> > If there is still time for SLF4J 2.0, I propose changing the Logger
> > methods that take a String to accept an Object instead (excl. the
> > methods that take format params); this enables various use cases and
> > optimizations in SLF4J implementations that are not possible with the
> > String-based API.
>
> Yes, there is still time to make changes.
>
> > One potential use case is a garbage-free implementations of the API. A
> > Logger implementation could check if the specified Object implements
> > java.lang.CharSequence, for example, and extract the message text
> > without allocating a temp String object. GC-sensitive apps could then
> > log StringBuilder objects, for example.
>
> Can you give a minimal example? String implements CharSequence. Do you
> mean another implementation of CharSquence like StringBuilder?


Sure. One example application could look like this:

public class ExampleApp {
    private Logger logger = LoggerFactory.getLogger(ExampleApp.class);
    private StringBuilder sb = new StringBuilder();

    public void onNewOrder(IOrder order) {
        log(order);
        performBusinessLogic(order);
    }

    private void log(IOrder order) {
        sb.setLength(0); // clear previous content
        sb.append("Received ");
        order.toString(sb); // put text representation of the order into SB
        logger.info(sb); // log it (without allocating temp objects)
    }
    // ...
}

class OrderImpl implements IOrder {
    /** Writes a textual representation of this order into the specified
     * StringBuilder, without allocating temporary objects.
     */
    public void toString(StringBuilder sb) {
        sb.append("NewOrder[")
                .append("account=").append(getAccount()) // CharSequence
                .append(", instrumentId=").append(getInstrumentId()) // int
                .append(", quantity=").append(getQty()) // long
                .append(", side=").append(getSide()) // enum (BUY,
SELL, SHORT-SELL, etc)
                .append("]");
    }
    // ...
}
>
> What would you do with the StringBuilder passed by the user?


Well, the simplest thing that a Logger implementation could do with the
Object that is passed as the message is to simply call toString on it
(or String.valueOf(message) to deal with null values).
This is all that slf4j-simple or logback would need to do.

I am guessing you are asking how one could go one step further and
make the actual logger implementation completely garbage-free.
For text-based loggers, one idea is to extract the text from the specified
domain Object (it may not be a CharSequence, but it may implement
some other interface that allows creating a text representation), and to
copy this text representation into a StringBuilder owned by the Logger.

The next step is to turn the text representation into bytes which can be
written to disk or sent over a network. For this, the logging
implementation needs to do some work with java.nio.CharBuffer, ByteBuffer
and CharsetEncoders (and making this thread-safe can be quite involved).

>
> Or maybe the
> StringBuilder is provided by the logging back-end and only borrowed by
> the client?

That is a very good point!
(And that is one of the reasons why focusing too much on just
CharBuilder would be a mistake in my opinion.)

A SLF4J implementation could provide its own interface that applications
could implement on objects that need to be logged without allocations.
For example:

interface StringBuilderFormattable {
    /**
     * Writes a text representation of this object into the specified
     * StringBuilder, ideally without allocating temporary objects.
     *
     * @param buffer the StringBuilder to write into
     */
    void formatTo(StringBuilder buffer);
}

The SLF4J implementation detects that the logged Object implements
this interface, then calls the formatTo(StringBuilder) method on it with
the StringBuilder owned by the logger. This has the advantage that the
application no longer needs to manage any StringBuilders, and it
reduces copying between various buffers. For example:

// example SLF4J logging implementation
@Override
protected void handleNormalizedLoggingCall(Level level, Marker marker,
        Object msg, Object[] arguments, Throwable throwable) {

    StringBuilder sb = getStringBuilder(); // owned by the logger
    extractText(msg, sb);

    List<StringBuilder> textArgs = getStringBuilders(arguments.length);
    for (int i = 0; i < arguments.length; i++) {
        extractText(arguments[i], textArgs.get(i);
    }
    handleTextLoggingCall(level, marker, sb, textArgs, throwable);
}

private void extractText(Object obj, StringBuilder sb) {
    if (obj instanceof StringBuilderFormattable) {
        ((StringBuilderFormattable) obj).formatInto(sb);
    } else if (obj instanceof CharSequence) {
        sb.append((CharSequence) obj));

    // unbox auto-boxed primitives to avoid calling toString()
    } else if (obj instanceof Integer) {
        sb.append(((Integer) obj).intValue());
    } else if (obj instanceof Double) {
        sb.append(((Double) obj).doubleValue());
    //... etc for other primitive boxed types

    } else {
        sb.append(obj.toString()); // fall back to toString
    }
}

Custom interfaces like StringBuilderFormattable would require cooperation
between the application and the logger implementation, so not everyone
may like this, but SLF4J should not make this impossible.

>
>
> Anyway, a minimal example would be helpful.
>
> > Another use case is binary logging; if the logging implementation has an
> > efficient way to map domain objects to a binary representation (as
> > opposed to a textual representation), then this could be both faster and
> > produce more compact output, which may be of interest to a certain type
> > of applications. The binary presentation could be converted back to text
> > offline or on-demand. Such use cases are not possible if the SLF4J API
> > only provides methods that accept Strings: information has been lost by
> > the time the logging implementation is invoked.
>
> Binary logging does not make sense to me. Anyway, if that is OK with
> you, let us not dwell on binary logging and see if the CharSequence case
> can stand on its own legs.

You might be surprised:
Recent (2018) work by Stephen Yang, Seo Jin Park, and John Ousterhout
at Stanford University resulted in this paper: "NanoLog: A Nanosecond
Scale Logging System"
https://www.usenix.org/system/files/conference/atc18/atc18-yang.pdf

Part of the performance gains is attributed to their compressed binary
logging format, and part due to preprocessing (doing work at compile time).
They have made their work open source:
https://github.com/PlatformLab/NanoLog

My main point is that, for SLF4J to be a truly generic facade that can be
used with a wide range of logging implementations, it would be a shame to
a priori exclude all categories other than text-based logging.

>
> > I cannot think of any downside, only upside, of replacing methods like
> > Logger.info(String) with Logger.info(Object) in the API. For API users
> > this would be a backwards compatible change.
>
> Source code compatibility is obviously would not be an issue. However, I
> am not 100% sure if changing the input types from String to Object does
> not break the client binary. Anyway, there is another solution where a
> not break the client binary. Anyway, there is another solution where a
> default implementation of Logger.info(CharSequence) is added to the
> Logger interface.

I stand corrected. You are right, and I was wrong: for client binaries
replacing Logger.info(String) with Logger.info(Object) _is_ an
incompatible change, resulting in errors like
java.lang.NoSuchMethodError: Logger.info(Ljava/lang/String;)V

I like your idea to solve this by keeping the existing methods in place
and adding other methods with a different signature.

I would argue that the new methods to add should take Object as parameter,
and the existing methods could have default implementations that
invoke their new equivalent method that takes an Object.



>
> > API implementations would need to do something extra to get the textual
> > representation from the specified Object, but not much - this could be
> > as simple as calling toString on it.
> >
> > However, an Object-based API opens the door for various use cases and
> > optimizations in SLF4J implementations that are otherwise not possible,
> > as suggested above. I'm hoping that the 2.0 major release would be an
> > opportunity for such changes...
>
> Depending on the vantage point, a user might have different requirements
> from the logging API. Thus all suggestions are welcome.
> > Thoughts?
> >
> > Remko.
> >
> --
> Ceki Gülcü
> _______________________________________________
> slf4j-dev mailing list
> slf4j-dev at qos.ch
> http://mailman.qos.ch/mailman/listinfo/slf4j-dev