One downside to logging Objects is that the logging library needs to watch out for recursion. IOW, invoking an object's toString() may end up doing some logging itself. Gary On Tue, Dec 17, 2019 at 2:36 PM Ceki <ceki@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? What would you do with the StringBuilder passed by the user? Or maybe the StringBuilder is provided by the logging back-end and only borrowed by the client?

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.

...

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 default implementation of Logger.info(CharSequence) is added to the Logger interface.

...

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@qos.ch http://mailman.qos.ch/mailman/listinfo/slf4j-dev

Hi Ceki, sorry, I caught a stomach bug. Give me a day or so to reply properly. -Remko On Wed, Dec 18, 2019 at 4:36 Ceki <ceki@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? What would you do with the StringBuilder passed by the user? Or maybe the StringBuilder is provided by the logging back-end and only borrowed by the client?

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.

...

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 default implementation of Logger.info(CharSequence) is added to the Logger interface.

...

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@qos.ch http://mailman.qos.ch/mailman/listinfo/slf4j-dev

Am 17.12.19 um 20:36 schrieb Ceki:

...

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.

Heh. While we're at it, I have a similar suggestion to make: Allow arbitrary objects as MDC values, and possibly keys as well. I had two use cases in the past: 1. I had enter/exit logging, and wanted to determine nesting depth in the Appender, for generating an indent (and the DatabaseAppender was supposed to link each message to its parent Enter message). I had to keep the state in the MDC because that was the only thread-safe place I could find, and I had to serialize/deserialize the data. It sort-of worked, but it was ugly, and there were obvious inefficiencies. (There are more ramifications about nested log messages, it's probably smarter to directly support this in SLF4J. E.g. if an Enter message is not appended in its own right, it might still have to be if an inner message is appended.) 2. I had MDC objects that would usually not be logged, and that had an expensive toString() operation. I wanted to make the toString() call lazy and cache the result, but MDC does not accept anything but String, so that was just impossible. (I can imagine workarounds. Like a weak reference map and storing just a key in the MDC value. Write a Formatter that substitutes not the value but the referenced object. It's complicated and error-prone, and Formatters don't compose easily, plus it's in the backend logger and not in SLF4J where it should be.) Regards, Jo

On Wed, Dec 18, 2019 at 4:36 AM Ceki <ceki@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@qos.ch http://mailman.qos.ch/mailman/listinfo/slf4j-dev

On Thu, Dec 19, 2019 at 3:23 PM Ralph Goers <ralph.goers@dslextreme.com> wrote:

On Dec 18, 2019, at 11:01 PM, Remko Popma <remko.popma@gmail.com> wrote:

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:

As soon as you do this, and require that the implementation start checking if particular interfaces are implemented

Nothing is "required": my example illustrated one way for implementations who want to provide extra benefits to do so, other implementations can simply call toString on the Object.

I have to say, why not use a Message instead. The Message interface has four methods, which makes it a bit more cumbersome for domain objects to implement. I suspect that only some applications with specific needs would take the trouble to implement Message in their domain objects. So I would say, perhaps use a Message in addition, but not instead of Object.

The Log4j API has been doing this for years now. It has solved the problems you are bringing up nicely. The Message interface in the Log4j API is useful, but it does not solve any of the problems I indicated. The main problem to me is that it is still String-based. If SLF4J were to adopt a Message-like interface I would argue that its methods should return CharSequence instead of String. However, in terms of being useful for allocation-sensitive application, even such a revamped Message interface would still require domain objects to manage their own StringBuilders, so an interface like StringBuilderFormattable where the StringBuilder is supplied externally would be even more useful.

In fact I am pretty sure you implemented making some Messages reusable to make them garbage free. Yes, we added a ReusableMessage interface that extends Message and StringBuilderFormattable. That was necessary to allow the logger implementation to extract the text without allocating.

SLf4J wouldn’t have to do this. If it were to support a MessageFactory interface Log4j’s SLF4J binding could provide MessageFactories that implement Log4j’s Message interface so SLF4J (and Log4j) would be garbage free via the logging implementation, at least for some Message classes.

Since you have admitted that you have to leave the existing methods alone, why not just go all the way?

As you well know, the Log4j API still allows users to log Strings or arbitrary Objects. Under the covers it just puts them into a Message. The benefit here is that the logging implementation doesn’t have to check for all kinds of interfaces - it just processes the Message interface. SLF4J could do the same thing.

I'm not opposed to introducing a Message interface in the SLF4J API, but it should not replace logging arbitrary objects with Logger.info(Object).

Ralph _______________________________________________ slf4j-dev mailing list slf4j-dev@qos.ch http://mailman.qos.ch/mailman/listinfo/slf4j-dev

On Thu, Dec 19, 2019 at 23:46 Ceki <ceki@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@qos.ch http://mailman.qos.ch/mailman/listinfo/slf4j-dev

All, Happy New Year! Ceki, have you had a chance to consider my proposal? I still strongly believe that having a logging API that allows Objects to be logged: 1) opens various possibilities for logging implementations 2) has few (if any) drawbacks. Thoughts? Kind regards, Remko On Fri, Dec 20, 2019 at 6:08 AM Ceki <ceki@qos.ch> wrote:

On 19.12.2019 21:35, Remko Popma wrote:

...

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)?

Thank you for the link. I am reading right now. _______________________________________________ slf4j-dev mailing list slf4j-dev@qos.ch http://mailman.qos.ch/mailman/listinfo/slf4j-dev