[slf4j-dev] Proposal for SLF4J 2.0 Logger API

[Remko Popma]

On Thu, Dec 19, 2019 at 23:46 Ceki <ceki at qos.ch> wrote:

>
>
> On 19.12.2019 07:01, Remko Popma wrote:
>
> >
> > 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("]");
> >      }
> >      // ...
> > }
>
> In the example above, one could simply change a single line without
> requiring any change to the SLF4J API.
>
>       private void log(IOrder order) {
>            sb.setLength(0);
>            sb.append("Received ");
>            order.toString(sb);
>            logger.info(sb.toString()); // changed line
>       }

Yes, that is my main complaint: SLF4J currently _forces_ applications to
transform the original raw data to a text representation. Why? Or rather,
why so soon? This is too soon! The original data had information that is
lost by the time it reaches the logging backend. A whole range of
interesting possibilities are now no longer available because we don’t have
the original data but only a text representation to work with.

>
>
> >> 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.
>
> Adding Logger.debug(Object) method would allow the above implementation
> in logging backends but would not guide/help/encourage usage of
> StringBuilderFormattable. It think more restricted typing (instead of
> just Object) would encourage adoption.
>

Perhaps we got a bit sidetracked with the discussion about Message and
StringBuilderFormattable.
Garbage-free logging backends is only one of the possibilities that is
precluded by the current String-based API.

For the SLF4J API to be genuinely generic enough to span the requirements
and abilities of many possible logging backends, it should not be too
opinionated.

Have you had a chance to look at Yang et al’s work on NanoLog (
https://www.usenix.org/system/files/conference/atc18/atc18-yang.pdf,
https://github.com/PlatformLab/NanoLog)?

One of the reasons they could achieve those performance numbers is by
_postponing_ formatting.

I believe there are many advantages in allowing applications to log the
original domain objects instead of a derived representation.


>
> --
> Ceki Gülcü
> _______________________________________________
> slf4j-dev mailing list
> slf4j-dev at qos.ch
> http://mailman.qos.ch/mailman/listinfo/slf4j-dev
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.qos.ch/pipermail/slf4j-dev/attachments/20191220/22a38515/attachment.html>