You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by John Vasileff <jo...@gmail.com> on 2011/09/15 18:32:53 UTC

log4j2 parameterized msg with throwable

Should logs that use ParameterizedMessage support trailing throwables? The ParameterizedMessage code identifies throwables in the argument array, but they are silently ignored.  This is for methods like:

void info(String message, Object... params);

Example:

log4j2Logger.info("log4j2Logger no params with throwable?", t); // works
log4j2Logger.info("log4j2Logger {}", "params with throwable?", t); // fails

Output:

2011-09-15 11:55:40,497 INFO Log4j2Testing [main] log4j2Logger no params with throwable?
 java.lang.Throwable
	at Log4j2Testing.main(Log4j2Testing.java:18)
2011-09-15 11:55:40,499 INFO Log4j2Testing [main] log4j2Logger params with throwable?


On a related note, consider Logger methods like the following:

void info(Message msg);
void info(Message msg, Throwable t);

If Message objects support Throwables, as may be true for ParameterizedMessage or future message types (end user created or new to be conceived log4j2 standard messages), there is ambiguity in the second method as to which throwable is "the" throwable.  Perhaps the first non-null, or maybe the explicit argument overrides the msg throwable.  In any case, it is a bit confusing.

Perhaps the second method with an explicit Throwable should be eliminated, and Message objects should support Throwables when desired.  getThrowable() could be added to the Message interface, or even a separate MessageWithThrowable interface similar to the way FormattedMessage works.  (The former may be better to avoid having too many interfaces and instanceof clutter.)

It seems to me that throwables are a natural part of messages, just as the formatted message strings and parameters are.

It doesn't look like adding throwables to Messages would cause additional overhead.  In cases like ParameterizedMessage, it standardizes the approach to throwables and gives the Message object more power.  In other cases, it just changes the location of a parenthesis in the code:

public void info(String message, Throwable t) {
    if (isEnabled(Level.INFO, null, message, t)) {
        log(null, getFQCN(), Level.INFO, new SimpleMessage(message), t);
    }
}

becomes:
...
        log(null, getFQCN(), Level.INFO, new SimpleMessage(message, t));
...



John
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 16, 2011, at 4:41 PM, Joern Huxhorn wrote:

> But what about tracing messages? Those could have a TraceMessageType (ENTERING, EXITING, THROWING).
> Shouldn't we add that to the Message interface, too, and just return null in case of every other Message implementation?
> 
> Sorry about my sarcasm (and yes, that's only sarcasm. I'm not suggesting to add this to the Message interface ;)) but I just don't see the reason and rationale for those methods.

It may be sarcasm but I really could see logger.entry being implemented as

    public void entry(Object... params) {
        if (isEnabled(Level.TRACE, ENTRY_MARKER, (Object) null, null)) {
            log(ENTRY_MARKER, getFQCN(), Level.TRACE, new EntryMessage(params), null);
        }
    }

public class EntryMessage extends SimpleMessage {
    public EntryMessage(Object[] params) {
        super(getMsg(params));
    }

    private String getMsg(Object[] params) {
        if (params == null) {
            return " entry";
        }
        StringBuilder sb = new StringBuilder(" entry parms(");
        int i = 0;
        for (Object parm : params) {
            if (parm != null) {
                sb.append(parm.toString());
            } else {
                sb.append("null");
            }
            if (++i < params.length) {
                sb.append(", ");
            }
        }
        sb.append(")");
        return sb.toString();
    }
}
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Joern Huxhorn <jh...@googlemail.com>.
On 17.09.2011, at 21:34, Ralph Goers wrote:

> 
> On Sep 17, 2011, at 12:26 PM, Joern Huxhorn wrote:
> 
>> 
>> The code simply looks like this:
>> public void log(Level level, String messagePattern, Object... args) {
>> 	if (!isEnabled(level)) return;
>> 	ParameterizedMessage message = ParameterizedMessage.create(messagePattern, args);
>> 	performLogging(level, null, message, message.getThrowable());
>> }
> 
> Thanks. This is the source of the bug.  The API is currently not doing message.getThrowable(). I'll fix that shortly.
> 
> But I also do like John's suggestion that ParameterizedMessage and StructuredDataMessage could be interfaces. What are your thoughts on that?

May make sense.
I'm not sure, yet, where this would be of actual use but I wouldn't rule it out because of that.

One thing that makes me keeps poking me concerning this suggestion is the fact that the RFC5424 StructuredDataMessage has specific requirements concerning the key-length while other implementations likely wouldn't. This means that those implementations couldn't simply be exchanged since RFC5424 would throw an, say, IllegalArgumentException for a key longer than 32 chars while others wouldn't.

Joern.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 17, 2011, at 12:26 PM, Joern Huxhorn wrote:

> 
> The code simply looks like this:
> public void log(Level level, String messagePattern, Object... args) {
> 	if (!isEnabled(level)) return;
> 	ParameterizedMessage message = ParameterizedMessage.create(messagePattern, args);
> 	performLogging(level, null, message, message.getThrowable());
> }

Thanks. This is the source of the bug.  The API is currently not doing message.getThrowable(). I'll fix that shortly.

But I also do like John's suggestion that ParameterizedMessage and StructuredDataMessage could be interfaces. What are your thoughts on that?

Ralph


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by John Vasileff <jo...@gmail.com>.
On Sep 17, 2011, at 3:26 PM, Joern Huxhorn wrote:

> 
> On 17.09.2011, at 21:02, John Vasileff wrote:
> 
>> 
>> On Sep 17, 2011, at 2:40 PM, Joern Huxhorn wrote:
>> 
>>> 
>>> On 17.09.2011, at 18:47, John Vasileff wrote:
>>> 
>>>> 
>>>> On Sep 17, 2011, at 8:53 AM, Joern Huxhorn wrote:
>>>> 
>>>>> Adding getThrowable() would also reintroduce the issue that such a Message could not be serialized securely since deserialization would require the exceptions class on the classpath. In my ParameterizedMessage over at https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/n/messages/ParameterizedMessage.java the Throwable is transient so it is deliberately lost while serializing, i.e. it must be taken care of by the framework immediately after the message is created.
>>>>> 
>>>>> It is only contained in ParameterizedMessage at all simply because a method can only return a single value. And the create-method is also responsible for resolving the Throwable at the last position of arguments if it is not used up by a corresponding {}.
>>>>> 
>>>>> Yes, it would be "cleaner" to split that into a parseresult object that contains both the message and an additional, optional Throwable. I just didn't implement it that way to reduce the amount of garbage (that parseresult object would get garbage-collected immediately after evaluation).
>>>>> 
>>>>> So adding Throwable to ParameterizedMessage was just a performance optimization.
>>>>> 
>>>>> The serialization issue is btw also the reason for *not* having Object[] getParameters() but String[] getParameters() instead. The String representation is the serialization-safe version of the parameters.
>>>>> 
>>>>> But all of this is, in my books, an implementation detail of the Message implementation with getFormattedMessage() being the only "public" API of Message.
>>>>> 
>>>>> Joern.
>>>>> ---------------------------------------------------------------------
>>>>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>>>>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>>>>> 
>>>> 
>>>> Interesting point on serialization.  When would you see serialization happening?  Is this primarily for appenders?
>>>> 
>>> 
>>> SocketAppender is using serialization. Since I'm the author of Lilith ( http://lilith.huxhorn.de/ ) I tend to focus on stuff like that.
>>> 
>>> This is also the reason for the differentiation between the Message instance and the (laziliy) formatted  message string. A SocketAppender does not have any need for a formatted message. It is perfectly valid to skip the formatting entirely and simply transmit the message pattern and the message parameters (as Strings) to safe some CPU in the logged application.
>>> 
>>> Directly converting parameters into Strings as soon as we know that an event really needs to be created is crucial to make sure that the logging framework is not lying as is happening, for example, in this case: http://techblog.appnexus.com/2011/webkit-chrome-safari-console-log-bug/
>>> A lying logging framework is really, really bad...
>>> 
>>> Joern.
>> 
>> So, the two most significant points are:
>> 
>> 1) ambiguity with info(Message msg, Throwable throwable) where for all practical purposes Message will at least sometimes also have a throwable.  Minor additional point that having log methods with explicit Throwables adds several methods to the Logger interface.
>> 
>> 2) issue with serializing appenders having to special case 'transient Throwable' in message objects (i.e. the appender would have to call getThrowable(), convert to String, and store separately from the message object.)
>> 
>> My opinion is that Logger is by far the most important interface and design decisions should give preference to application developer facing interfaces.  Thoughts?
> 
> 
> The code simply looks like this:
> public void log(Level level, String messagePattern, Object... args) {
> 	if (!isEnabled(level)) return;
> 	ParameterizedMessage message = ParameterizedMessage.create(messagePattern, args);
> 	performLogging(level, null, message, message.getThrowable());
> }
> 
> public void log(Level level, Marker marker, String messagePattern, Object... args) {
> 	if (!isEnabled(level, marker)) return;
> 	ParameterizedMessage message = ParameterizedMessage.create(messagePattern, args);
> 	performLogging(level, marker, message, message.getThrowable());
> }
> 
> public void log(Level level, Message message) {
> 	if (!isEnabled(level)) return;
> 	if (message instanceof ParameterizedMessage) {
> 		performLogging(level, null, message, ((ParameterizedMessage) message).getThrowable());
> 	} else {
> 		performLogging(level, null, message, null);
> 	}
> }
> 
> public void log(Level level, Message message, Throwable throwable) {
> 	if (!isEnabled(level)) return;
> 	performLogging(level, null, message, throwable);
> }
> 
> public void log(Level level, Marker marker, Message message) {
> 	if (!isEnabled(level, marker)) return;
> 	if (message instanceof ParameterizedMessage) {
> 		performLogging(level, marker, message, ((ParameterizedMessage) message).getThrowable());
> 	} else {
> 		performLogging(level, marker, message, null);
> 	}
> }
> 
> public void log(Level level, Marker marker, Message message, Throwable throwable) {
> 	if (!isEnabled(level, marker)) return;
> 	performLogging(level, marker, message, throwable);
> }


Fixes would be required for all classes extending AbstractLogger that implement:

protected abstract void log(Marker marker, String fqcn, Level level, Message data, Throwable t);
and
protected abstract boolean isEnabled(Level level, Marker marker, Message data, Throwable t);

Alternately, the numerous:

public void trace|debug|..(Marker? marker, Message msg, Throwable? t);

of AbstractLogger could include this logic.  Granted, redundant code could be avoided with "private void resolveThrowableAndLog(...)" in AbstractLogger that is called by the numerous methods.  Third party implementations of Logger that do not extend AbstractLogger would need to do this as well.

Appenders, Filters, etc. probably don't need this check if resolving throwables is handled by all front end methods.  But, given that messages may have a throwable, the contract that non-front-end code isn't required to resolve throwables is not clearly communicated by the method signatures.

Further... today ParameterizedMessages are allowed to define a throwable.  Tomorrow there may be other types such as JavaFormattedMessage.  So, the above code does not remove the requirement for a ThrowableMessage type.  It should be "instance of ThrowableMessage".


> 
> If a method with just a Message but no Throwable is called then this Message is checked if it is a ParameterizedMessage. Otherwise null is used for the Throwable. If, however, a method with an explicit Throwable is used then this Throwable is used for logging.
> The whole point of having the Throwable in ParameterizedMessage is simply because create can only return a single value without creating additional overhead caused by wrappers. The Throwable is not meant to be part of the Message, it just happens to be like that directly after creation - but not after deserialization! It's the job of the logging framework to handle the Throwable in a sensible way.
> 
> Perhaps making getThrowable() package-private would make this more clear but I'd have to move classes around in a non-logical way just to achieve this. Do not want.
> 

Despite implementation challenges above, the core of the problem I see is not with the getThrowable() method.  It is with the dilemma faced by application developers deciding if providing a Throwable in a Message object is sufficient, or if it should also be provided as a log method argument, or maybe only as a log method argument.  Including your above notes in the javadocs for info(msg, throwable) type methods would help resolve this.  But considering a throwable as a part of the message data and removing what would then be "extra" methods eliminates the dilemma altogether.

For a JavaFormattedMessage class that also handles a trailing throwable, all users would face the above dilemma, as would users that want to instantiate ParameterizedMessage directly.


> Joern.
> 


John
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Joern Huxhorn <jh...@googlemail.com>.
On 17.09.2011, at 21:02, John Vasileff wrote:

> 
> On Sep 17, 2011, at 2:40 PM, Joern Huxhorn wrote:
> 
>> 
>> On 17.09.2011, at 18:47, John Vasileff wrote:
>> 
>>> 
>>> On Sep 17, 2011, at 8:53 AM, Joern Huxhorn wrote:
>>> 
>>>> Adding getThrowable() would also reintroduce the issue that such a Message could not be serialized securely since deserialization would require the exceptions class on the classpath. In my ParameterizedMessage over at https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/n/messages/ParameterizedMessage.java the Throwable is transient so it is deliberately lost while serializing, i.e. it must be taken care of by the framework immediately after the message is created.
>>>> 
>>>> It is only contained in ParameterizedMessage at all simply because a method can only return a single value. And the create-method is also responsible for resolving the Throwable at the last position of arguments if it is not used up by a corresponding {}.
>>>> 
>>>> Yes, it would be "cleaner" to split that into a parseresult object that contains both the message and an additional, optional Throwable. I just didn't implement it that way to reduce the amount of garbage (that parseresult object would get garbage-collected immediately after evaluation).
>>>> 
>>>> So adding Throwable to ParameterizedMessage was just a performance optimization.
>>>> 
>>>> The serialization issue is btw also the reason for *not* having Object[] getParameters() but String[] getParameters() instead. The String representation is the serialization-safe version of the parameters.
>>>> 
>>>> But all of this is, in my books, an implementation detail of the Message implementation with getFormattedMessage() being the only "public" API of Message.
>>>> 
>>>> Joern.
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>>>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>>>> 
>>> 
>>> Interesting point on serialization.  When would you see serialization happening?  Is this primarily for appenders?
>>> 
>> 
>> SocketAppender is using serialization. Since I'm the author of Lilith ( http://lilith.huxhorn.de/ ) I tend to focus on stuff like that.
>> 
>> This is also the reason for the differentiation between the Message instance and the (laziliy) formatted  message string. A SocketAppender does not have any need for a formatted message. It is perfectly valid to skip the formatting entirely and simply transmit the message pattern and the message parameters (as Strings) to safe some CPU in the logged application.
>> 
>> Directly converting parameters into Strings as soon as we know that an event really needs to be created is crucial to make sure that the logging framework is not lying as is happening, for example, in this case: http://techblog.appnexus.com/2011/webkit-chrome-safari-console-log-bug/
>> A lying logging framework is really, really bad...
>> 
>> Joern.
> 
> So, the two most significant points are:
> 
> 1) ambiguity with info(Message msg, Throwable throwable) where for all practical purposes Message will at least sometimes also have a throwable.  Minor additional point that having log methods with explicit Throwables adds several methods to the Logger interface.
> 
> 2) issue with serializing appenders having to special case 'transient Throwable' in message objects (i.e. the appender would have to call getThrowable(), convert to String, and store separately from the message object.)
> 
> My opinion is that Logger is by far the most important interface and design decisions should give preference to application developer facing interfaces.  Thoughts?


The code simply looks like this:
public void log(Level level, String messagePattern, Object... args) {
	if (!isEnabled(level)) return;
	ParameterizedMessage message = ParameterizedMessage.create(messagePattern, args);
	performLogging(level, null, message, message.getThrowable());
}

public void log(Level level, Marker marker, String messagePattern, Object... args) {
	if (!isEnabled(level, marker)) return;
	ParameterizedMessage message = ParameterizedMessage.create(messagePattern, args);
	performLogging(level, marker, message, message.getThrowable());
}

public void log(Level level, Message message) {
	if (!isEnabled(level)) return;
	if (message instanceof ParameterizedMessage) {
		performLogging(level, null, message, ((ParameterizedMessage) message).getThrowable());
	} else {
		performLogging(level, null, message, null);
	}
}

public void log(Level level, Message message, Throwable throwable) {
	if (!isEnabled(level)) return;
	performLogging(level, null, message, throwable);
}

public void log(Level level, Marker marker, Message message) {
	if (!isEnabled(level, marker)) return;
	if (message instanceof ParameterizedMessage) {
		performLogging(level, marker, message, ((ParameterizedMessage) message).getThrowable());
	} else {
		performLogging(level, marker, message, null);
	}
}

public void log(Level level, Marker marker, Message message, Throwable throwable) {
	if (!isEnabled(level, marker)) return;
	performLogging(level, marker, message, throwable);
}

If a method with just a Message but no Throwable is called then this Message is checked if it is a ParameterizedMessage. Otherwise null is used for the Throwable. If, however, a method with an explicit Throwable is used then this Throwable is used for logging.
The whole point of having the Throwable in ParameterizedMessage is simply because create can only return a single value without creating additional overhead caused by wrappers. The Throwable is not meant to be part of the Message, it just happens to be like that directly after creation - but not after deserialization! It's the job of the logging framework to handle the Throwable in a sensible way.

Perhaps making getThrowable() package-private would make this more clear but I'd have to move classes around in a non-logical way just to achieve this. Do not want.

Joern.



---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by John Vasileff <jo...@gmail.com>.
On Sep 17, 2011, at 2:40 PM, Joern Huxhorn wrote:

> 
> On 17.09.2011, at 18:47, John Vasileff wrote:
> 
>> 
>> On Sep 17, 2011, at 8:53 AM, Joern Huxhorn wrote:
>> 
>>> Adding getThrowable() would also reintroduce the issue that such a Message could not be serialized securely since deserialization would require the exceptions class on the classpath. In my ParameterizedMessage over at https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/n/messages/ParameterizedMessage.java the Throwable is transient so it is deliberately lost while serializing, i.e. it must be taken care of by the framework immediately after the message is created.
>>> 
>>> It is only contained in ParameterizedMessage at all simply because a method can only return a single value. And the create-method is also responsible for resolving the Throwable at the last position of arguments if it is not used up by a corresponding {}.
>>> 
>>> Yes, it would be "cleaner" to split that into a parseresult object that contains both the message and an additional, optional Throwable. I just didn't implement it that way to reduce the amount of garbage (that parseresult object would get garbage-collected immediately after evaluation).
>>> 
>>> So adding Throwable to ParameterizedMessage was just a performance optimization.
>>> 
>>> The serialization issue is btw also the reason for *not* having Object[] getParameters() but String[] getParameters() instead. The String representation is the serialization-safe version of the parameters.
>>> 
>>> But all of this is, in my books, an implementation detail of the Message implementation with getFormattedMessage() being the only "public" API of Message.
>>> 
>>> Joern.
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>>> 
>> 
>> Interesting point on serialization.  When would you see serialization happening?  Is this primarily for appenders?
>> 
> 
> SocketAppender is using serialization. Since I'm the author of Lilith ( http://lilith.huxhorn.de/ ) I tend to focus on stuff like that.
> 
> This is also the reason for the differentiation between the Message instance and the (laziliy) formatted  message string. A SocketAppender does not have any need for a formatted message. It is perfectly valid to skip the formatting entirely and simply transmit the message pattern and the message parameters (as Strings) to safe some CPU in the logged application.
> 
> Directly converting parameters into Strings as soon as we know that an event really needs to be created is crucial to make sure that the logging framework is not lying as is happening, for example, in this case: http://techblog.appnexus.com/2011/webkit-chrome-safari-console-log-bug/
> A lying logging framework is really, really bad...
> 
> Joern.

So, the two most significant points are:

1) ambiguity with info(Message msg, Throwable throwable) where for all practical purposes Message will at least sometimes also have a throwable.  Minor additional point that having log methods with explicit Throwables adds several methods to the Logger interface.

2) issue with serializing appenders having to special case 'transient Throwable' in message objects (i.e. the appender would have to call getThrowable(), convert to String, and store separately from the message object.)

My opinion is that Logger is by far the most important interface and design decisions should give preference to application developer facing interfaces.  Thoughts?


John


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
Not as far as I can tell. I believe it was added in Java 1.5. Thread Information is referenced in JSR 174.

On Sep 18, 2011, at 5:32 PM, Scott Deboy wrote:

> That's optional though I believe. Oracle vm specific?
> 
>>> 
>>> I think http://download.oracle.com/javase/6/docs/api/java/lang/management/ThreadMXBean.html could be what you are looking for.
>>> Haven't given it a try, yet.
>> 
>> Thanks, I'll give it a try.
>> 
>> Ralph
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Scott Deboy <sc...@gmail.com>.
That's optional though I believe. Oracle vm specific?



On Sep 18, 2011, at 5:21 PM, Ralph Goers <ra...@dslextreme.com>  
wrote:

>
> On Sep 18, 2011, at 4:56 PM, Joern Huxhorn wrote:
>
>>
>> On 19.09.2011, at 01:29, Ralph Goers wrote:
>>
>>>
>>> On Sep 18, 2011, at 3:01 PM, Joern Huxhorn wrote:
>>>
>>>> Sorry, I was confused and mixed something up...
>>>>
>>>> I *planned* to implement a thread-specific sequence number but  
>>>> never did so. I also considered logging the ThreadGroup-hierarchy  
>>>> but didn't do so, yet, because of the expected performance impact.
>>>>
>>>> Which reminds me, completely off-topic, of another idea  
>>>> concerning a custom Message implementation:
>>>> A ThreadDumpMessage that would not get any parameter at all and  
>>>> would consist of a ThreadDump if it is actually logged, including  
>>>> the ThreadGroup info etc..
>>>> This would have helped me immensely in the past. Instead, I had  
>>>> to trigger thread dumps via SIG_QUIT at a random points of  
>>>> execution.
>>>>
>>>> Such a Message wouldn't be used in production under normal  
>>>> circumstances but could be enabled in case of strange concurrency  
>>>> issues...
>>>
>>> I added it, but as I said, I wish I knew how to include the locks.
>>>
>>> FWIW, I could have used this 2 days ago when we were trying to  
>>> debug just such a concurrency issue.
>>>
>>
>> I think http://download.oracle.com/javase/6/docs/api/java/lang/management/ThreadMXBean.html 
>>  could be what you are looking for.
>> Haven't given it a try, yet.
>
> Thanks, I'll give it a try.
>
> Ralph
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 18, 2011, at 4:56 PM, Joern Huxhorn wrote:

> 
> On 19.09.2011, at 01:29, Ralph Goers wrote:
> 
>> 
>> On Sep 18, 2011, at 3:01 PM, Joern Huxhorn wrote:
>> 
>>> Sorry, I was confused and mixed something up...
>>> 
>>> I *planned* to implement a thread-specific sequence number but never did so. I also considered logging the ThreadGroup-hierarchy but didn't do so, yet, because of the expected performance impact.
>>> 
>>> Which reminds me, completely off-topic, of another idea concerning a custom Message implementation:
>>> A ThreadDumpMessage that would not get any parameter at all and would consist of a ThreadDump if it is actually logged, including the ThreadGroup info etc..
>>> This would have helped me immensely in the past. Instead, I had to trigger thread dumps via SIG_QUIT at a random points of execution.
>>> 
>>> Such a Message wouldn't be used in production under normal circumstances but could be enabled in case of strange concurrency issues...
>> 
>> I added it, but as I said, I wish I knew how to include the locks. 
>> 
>> FWIW, I could have used this 2 days ago when we were trying to debug just such a concurrency issue.
>> 
> 
> I think http://download.oracle.com/javase/6/docs/api/java/lang/management/ThreadMXBean.html could be what you are looking for. 
> Haven't given it a try, yet.

Thanks, I'll give it a try.

Ralph
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Jacob Kjome <ho...@visi.com>.
Note that it's possible to change the boot classpath to include Java 1.6 API 
using a Java 1.5 compiler and compile the classes just fine.  I recommend 
against overloading the meaning of the "source" compiler flag to refer to Java 
API rather than the language features it is narrowly meant to refer to.

Jake

On Thu, 29 Sep 2011 11:55:21 -0700
 "ralph.goers @dslextreme.com" <ra...@dslextreme.com> wrote:
> Well, that is true as far as the Java Language spec goes. However, there is
> now a class that will only compile if JDK 1.6 is available as the classes
> are new to that release. So yes, even though the source code is 1.5
> compatible it still would be good to let people know that they have to use
> JDK 1.6 to compile.
> 
> Ralph
> 
> On Thu, Sep 29, 2011 at 9:42 AM, Jacob Kjome <ho...@visi.com> wrote:
> 
>>
>> Why would you need source=1.6?  The only binary incompatibility between 1.5
>> and 1.6 that I'm aware of is that in 1.6 you can use @Override for
>> overridden methods of an interface where 1.5 you can't.  What is it about
>> Java 1.6 that you require it for compilation?  If it's just API, then you
>> can still use source=1.5.
>>
>> Jake
>>
>>
>> On Wed, 28 Sep 2011 23:29:16 -0700
>>  Ralph Goers <ra...@dslextreme.com> wrote:
>>
>>>
>>> On Sep 19, 2011, at 1:44 AM, Joern Huxhorn wrote:
>>>
>>>
>>>> On 19.09.2011, at 09:36, Ralph Goers wrote:
>>>>
>>>>
>>>>> On Sep 18, 2011, at 4:56 PM, Joern Huxhorn wrote:
>>>>>
>>>>>
>>>>>> On 19.09.2011, at 01:29, Ralph Goers wrote:
>>>>>>
>>>>>>
>>>>>>> On Sep 18, 2011, at 3:01 PM, Joern Huxhorn wrote:
>>>>>>>
>>>>>>>  Sorry, I was confused and mixed something up...
>>>>>>>>
>>>>>>>> I *planned* to implement a thread-specific sequence number but never
>>>>>>>> did so. I also considered logging the ThreadGroup-hierarchy but didn't do
>>>>>>>> so, yet, because of the expected performance impact.
>>>>>>>>
>>>>>>>> Which reminds me, completely off-topic, of another idea concerning a
>>>>>>>> custom Message implementation:
>>>>>>>> A ThreadDumpMessage that would not get any parameter at all and would
>>>>>>>> consist of a ThreadDump if it is actually logged, including the ThreadGroup
>>>>>>>> info etc..
>>>>>>>> This would have helped me immensely in the past. Instead, I had to
>>>>>>>> trigger thread dumps via SIG_QUIT at a random points of execution.
>>>>>>>>
>>>>>>>> Such a Message wouldn't be used in production under normal
>>>>>>>> circumstances but could be enabled in case of strange concurrency issues...
>>>>>>>>
>>>>>>>
>>>>>>> I added it, but as I said, I wish I knew how to include the locks.
>>>>>>> FWIW, I could have used this 2 days ago when we were trying to debug
>>>>>>> just such a concurrency issue.
>>>>>>>
>>>>>>>
>>>>>> I think http://download.oracle.com/**javase/6/docs/api/java/lang/**
>>>>>> management/ThreadMXBean.html<http://download.oracle.com/javase/6/docs/api/java/lang/management/ThreadMXBean.html>could 
>>>>>>be what you are looking for. Haven't given it a try, yet.
>>>>>>
>>>>>
>>>>> Unfortunately, all the good lock information was added in 1.6.
>>>>>
>>>>>
>>>> Yes, it is calling for some reflection magic.
>>>> You'd have to reimplement LockInfo and MonitorInfo, though...
>>>>
>>>
>>> I believe I've solved this with the minimum amount of reflection. However,
>>> it now requires that Log4j 2 be compiled with Java 6. It should still be
>>> able to run on Java 5. I tried to declare that in the compiler plugin but it
>>> throws an exception if source = 1.6 and target = 1.5. I believe the enforcer
>>> plugin would do it though.
>>>
>>> Ralph
>>> ------------------------------**------------------------------**---------
>>> To unsubscribe, e-mail: 
>>>log4j-dev-unsubscribe@logging.**apache.org<lo...@logging.apache.org>
>>> For additional commands, e-mail: 
>>>log4j-dev-help@logging.apache.**org<lo...@logging.apache.org>
>>>
>>>
>>>
>>
>> ------------------------------**------------------------------**---------
>> To unsubscribe, e-mail: 
>>log4j-dev-unsubscribe@logging.**apache.org<lo...@logging.apache.org>
>> For additional commands, e-mail: 
>>log4j-dev-help@logging.apache.**org<lo...@logging.apache.org>
>>
>>


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by "ralph.goers @dslextreme.com" <ra...@dslextreme.com>.
Well, that is true as far as the Java Language spec goes. However, there is
now a class that will only compile if JDK 1.6 is available as the classes
are new to that release. So yes, even though the source code is 1.5
compatible it still would be good to let people know that they have to use
JDK 1.6 to compile.

Ralph

On Thu, Sep 29, 2011 at 9:42 AM, Jacob Kjome <ho...@visi.com> wrote:

>
> Why would you need source=1.6?  The only binary incompatibility between 1.5
> and 1.6 that I'm aware of is that in 1.6 you can use @Override for
> overridden methods of an interface where 1.5 you can't.  What is it about
> Java 1.6 that you require it for compilation?  If it's just API, then you
> can still use source=1.5.
>
> Jake
>
>
> On Wed, 28 Sep 2011 23:29:16 -0700
>  Ralph Goers <ra...@dslextreme.com> wrote:
>
>>
>> On Sep 19, 2011, at 1:44 AM, Joern Huxhorn wrote:
>>
>>
>>> On 19.09.2011, at 09:36, Ralph Goers wrote:
>>>
>>>
>>>> On Sep 18, 2011, at 4:56 PM, Joern Huxhorn wrote:
>>>>
>>>>
>>>>> On 19.09.2011, at 01:29, Ralph Goers wrote:
>>>>>
>>>>>
>>>>>> On Sep 18, 2011, at 3:01 PM, Joern Huxhorn wrote:
>>>>>>
>>>>>>  Sorry, I was confused and mixed something up...
>>>>>>>
>>>>>>> I *planned* to implement a thread-specific sequence number but never
>>>>>>> did so. I also considered logging the ThreadGroup-hierarchy but didn't do
>>>>>>> so, yet, because of the expected performance impact.
>>>>>>>
>>>>>>> Which reminds me, completely off-topic, of another idea concerning a
>>>>>>> custom Message implementation:
>>>>>>> A ThreadDumpMessage that would not get any parameter at all and would
>>>>>>> consist of a ThreadDump if it is actually logged, including the ThreadGroup
>>>>>>> info etc..
>>>>>>> This would have helped me immensely in the past. Instead, I had to
>>>>>>> trigger thread dumps via SIG_QUIT at a random points of execution.
>>>>>>>
>>>>>>> Such a Message wouldn't be used in production under normal
>>>>>>> circumstances but could be enabled in case of strange concurrency issues...
>>>>>>>
>>>>>>
>>>>>> I added it, but as I said, I wish I knew how to include the locks.
>>>>>> FWIW, I could have used this 2 days ago when we were trying to debug
>>>>>> just such a concurrency issue.
>>>>>>
>>>>>>
>>>>> I think http://download.oracle.com/**javase/6/docs/api/java/lang/**
>>>>> management/ThreadMXBean.html<http://download.oracle.com/javase/6/docs/api/java/lang/management/ThreadMXBean.html>could be what you are looking for. Haven't given it a try, yet.
>>>>>
>>>>
>>>> Unfortunately, all the good lock information was added in 1.6.
>>>>
>>>>
>>> Yes, it is calling for some reflection magic.
>>> You'd have to reimplement LockInfo and MonitorInfo, though...
>>>
>>
>> I believe I've solved this with the minimum amount of reflection. However,
>> it now requires that Log4j 2 be compiled with Java 6. It should still be
>> able to run on Java 5. I tried to declare that in the compiler plugin but it
>> throws an exception if source = 1.6 and target = 1.5. I believe the enforcer
>> plugin would do it though.
>>
>> Ralph
>> ------------------------------**------------------------------**---------
>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.**apache.org<lo...@logging.apache.org>
>> For additional commands, e-mail: log4j-dev-help@logging.apache.**org<lo...@logging.apache.org>
>>
>>
>>
>
> ------------------------------**------------------------------**---------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.**apache.org<lo...@logging.apache.org>
> For additional commands, e-mail: log4j-dev-help@logging.apache.**org<lo...@logging.apache.org>
>
>

Re: log4j2 parameterized msg with throwable

Posted by Jacob Kjome <ho...@visi.com>.
Why would you need source=1.6?  The only binary incompatibility between 1.5 
and 1.6 that I'm aware of is that in 1.6 you can use @Override for overridden 
methods of an interface where 1.5 you can't.  What is it about Java 1.6 that 
you require it for compilation?  If it's just API, then you can still use 
source=1.5.

Jake

On Wed, 28 Sep 2011 23:29:16 -0700
 Ralph Goers <ra...@dslextreme.com> wrote:
> 
> On Sep 19, 2011, at 1:44 AM, Joern Huxhorn wrote:
> 
>> 
>> On 19.09.2011, at 09:36, Ralph Goers wrote:
>> 
>>> 
>>> On Sep 18, 2011, at 4:56 PM, Joern Huxhorn wrote:
>>> 
>>>> 
>>>> On 19.09.2011, at 01:29, Ralph Goers wrote:
>>>> 
>>>>> 
>>>>> On Sep 18, 2011, at 3:01 PM, Joern Huxhorn wrote:
>>>>> 
>>>>>> Sorry, I was confused and mixed something up...
>>>>>> 
>>>>>> I *planned* to implement a thread-specific sequence number but never did so. 
>>>>>>I also considered logging the ThreadGroup-hierarchy but didn't do so, yet, 
>>>>>>because of the expected performance impact.
>>>>>> 
>>>>>> Which reminds me, completely off-topic, of another idea concerning a custom 
>>>>>>Message implementation:
>>>>>> A ThreadDumpMessage that would not get any parameter at all and would 
>>>>>>consist of a ThreadDump if it is actually logged, including the ThreadGroup 
>>>>>>info etc..
>>>>>> This would have helped me immensely in the past. Instead, I had to trigger 
>>>>>>thread dumps via SIG_QUIT at a random points of execution.
>>>>>> 
>>>>>> Such a Message wouldn't be used in production under normal circumstances but 
>>>>>>could be enabled in case of strange concurrency issues...
>>>>> 
>>>>> I added it, but as I said, I wish I knew how to include the locks. 
>>>>> 
>>>>> FWIW, I could have used this 2 days ago when we were trying to debug just 
>>>>>such a concurrency issue.
>>>>> 
>>>> 
>>>> I think 
>>>>http://download.oracle.com/javase/6/docs/api/java/lang/management/ThreadMXBean.html 
>>>>could be what you are looking for. 
>>>> Haven't given it a try, yet.
>>> 
>>> Unfortunately, all the good lock information was added in 1.6.  
>>> 
>> 
>> Yes, it is calling for some reflection magic.
>> You'd have to reimplement LockInfo and MonitorInfo, though...
> 
> I believe I've solved this with the minimum amount of reflection. However, 
>it now requires that Log4j 2 be compiled with Java 6. It should still be able 
>to run on Java 5. I tried to declare that in the compiler plugin but it 
>throws an exception if source = 1.6 and target = 1.5. I believe the enforcer 
>plugin would do it though.
> 
> Ralph
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>For additional commands, e-mail: log4j-dev-help@logging.apache.org
> 
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 19, 2011, at 1:44 AM, Joern Huxhorn wrote:

> 
> On 19.09.2011, at 09:36, Ralph Goers wrote:
> 
>> 
>> On Sep 18, 2011, at 4:56 PM, Joern Huxhorn wrote:
>> 
>>> 
>>> On 19.09.2011, at 01:29, Ralph Goers wrote:
>>> 
>>>> 
>>>> On Sep 18, 2011, at 3:01 PM, Joern Huxhorn wrote:
>>>> 
>>>>> Sorry, I was confused and mixed something up...
>>>>> 
>>>>> I *planned* to implement a thread-specific sequence number but never did so. I also considered logging the ThreadGroup-hierarchy but didn't do so, yet, because of the expected performance impact.
>>>>> 
>>>>> Which reminds me, completely off-topic, of another idea concerning a custom Message implementation:
>>>>> A ThreadDumpMessage that would not get any parameter at all and would consist of a ThreadDump if it is actually logged, including the ThreadGroup info etc..
>>>>> This would have helped me immensely in the past. Instead, I had to trigger thread dumps via SIG_QUIT at a random points of execution.
>>>>> 
>>>>> Such a Message wouldn't be used in production under normal circumstances but could be enabled in case of strange concurrency issues...
>>>> 
>>>> I added it, but as I said, I wish I knew how to include the locks. 
>>>> 
>>>> FWIW, I could have used this 2 days ago when we were trying to debug just such a concurrency issue.
>>>> 
>>> 
>>> I think http://download.oracle.com/javase/6/docs/api/java/lang/management/ThreadMXBean.html could be what you are looking for. 
>>> Haven't given it a try, yet.
>> 
>> Unfortunately, all the good lock information was added in 1.6.  
>> 
> 
> Yes, it is calling for some reflection magic.
> You'd have to reimplement LockInfo and MonitorInfo, though...

I believe I've solved this with the minimum amount of reflection. However, it now requires that Log4j 2 be compiled with Java 6. It should still be able to run on Java 5. I tried to declare that in the compiler plugin but it throws an exception if source = 1.6 and target = 1.5. I believe the enforcer plugin would do it though.

Ralph
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 19, 2011, at 1:44 AM, Joern Huxhorn wrote:

> 
> On 19.09.2011, at 09:36, Ralph Goers wrote:
> 
>> 
>> On Sep 18, 2011, at 4:56 PM, Joern Huxhorn wrote:
>> 
>>> 
>>> On 19.09.2011, at 01:29, Ralph Goers wrote:
>>> 
>>>> 
>>>> On Sep 18, 2011, at 3:01 PM, Joern Huxhorn wrote:
>>>> 
>>>>> Sorry, I was confused and mixed something up...
>>>>> 
>>>>> I *planned* to implement a thread-specific sequence number but never did so. I also considered logging the ThreadGroup-hierarchy but didn't do so, yet, because of the expected performance impact.
>>>>> 
>>>>> Which reminds me, completely off-topic, of another idea concerning a custom Message implementation:
>>>>> A ThreadDumpMessage that would not get any parameter at all and would consist of a ThreadDump if it is actually logged, including the ThreadGroup info etc..
>>>>> This would have helped me immensely in the past. Instead, I had to trigger thread dumps via SIG_QUIT at a random points of execution.
>>>>> 
>>>>> Such a Message wouldn't be used in production under normal circumstances but could be enabled in case of strange concurrency issues...
>>>> 
>>>> I added it, but as I said, I wish I knew how to include the locks. 
>>>> 
>>>> FWIW, I could have used this 2 days ago when we were trying to debug just such a concurrency issue.
>>>> 
>>> 
>>> I think http://download.oracle.com/javase/6/docs/api/java/lang/management/ThreadMXBean.html could be what you are looking for. 
>>> Haven't given it a try, yet.
>> 
>> Unfortunately, all the good lock information was added in 1.6.  
>> 
> 
> Yes, it is calling for some reflection magic.
> You'd have to reimplement LockInfo and MonitorInfo, though...

None of ThreadInfo, LockInfo and MonitorInfo are Serializable so new objects are required anyway. But doing it via reflection will make the code pretty ugly.

Ralph


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Joern Huxhorn <jh...@googlemail.com>.
On 19.09.2011, at 09:36, Ralph Goers wrote:

> 
> On Sep 18, 2011, at 4:56 PM, Joern Huxhorn wrote:
> 
>> 
>> On 19.09.2011, at 01:29, Ralph Goers wrote:
>> 
>>> 
>>> On Sep 18, 2011, at 3:01 PM, Joern Huxhorn wrote:
>>> 
>>>> Sorry, I was confused and mixed something up...
>>>> 
>>>> I *planned* to implement a thread-specific sequence number but never did so. I also considered logging the ThreadGroup-hierarchy but didn't do so, yet, because of the expected performance impact.
>>>> 
>>>> Which reminds me, completely off-topic, of another idea concerning a custom Message implementation:
>>>> A ThreadDumpMessage that would not get any parameter at all and would consist of a ThreadDump if it is actually logged, including the ThreadGroup info etc..
>>>> This would have helped me immensely in the past. Instead, I had to trigger thread dumps via SIG_QUIT at a random points of execution.
>>>> 
>>>> Such a Message wouldn't be used in production under normal circumstances but could be enabled in case of strange concurrency issues...
>>> 
>>> I added it, but as I said, I wish I knew how to include the locks. 
>>> 
>>> FWIW, I could have used this 2 days ago when we were trying to debug just such a concurrency issue.
>>> 
>> 
>> I think http://download.oracle.com/javase/6/docs/api/java/lang/management/ThreadMXBean.html could be what you are looking for. 
>> Haven't given it a try, yet.
> 
> Unfortunately, all the good lock information was added in 1.6.  
> 

Yes, it is calling for some reflection magic.
You'd have to reimplement LockInfo and MonitorInfo, though...

Joern.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 18, 2011, at 4:56 PM, Joern Huxhorn wrote:

> 
> On 19.09.2011, at 01:29, Ralph Goers wrote:
> 
>> 
>> On Sep 18, 2011, at 3:01 PM, Joern Huxhorn wrote:
>> 
>>> Sorry, I was confused and mixed something up...
>>> 
>>> I *planned* to implement a thread-specific sequence number but never did so. I also considered logging the ThreadGroup-hierarchy but didn't do so, yet, because of the expected performance impact.
>>> 
>>> Which reminds me, completely off-topic, of another idea concerning a custom Message implementation:
>>> A ThreadDumpMessage that would not get any parameter at all and would consist of a ThreadDump if it is actually logged, including the ThreadGroup info etc..
>>> This would have helped me immensely in the past. Instead, I had to trigger thread dumps via SIG_QUIT at a random points of execution.
>>> 
>>> Such a Message wouldn't be used in production under normal circumstances but could be enabled in case of strange concurrency issues...
>> 
>> I added it, but as I said, I wish I knew how to include the locks. 
>> 
>> FWIW, I could have used this 2 days ago when we were trying to debug just such a concurrency issue.
>> 
> 
> I think http://download.oracle.com/javase/6/docs/api/java/lang/management/ThreadMXBean.html could be what you are looking for. 
> Haven't given it a try, yet.

Unfortunately, all the good lock information was added in 1.6.  

Ralph
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Joern Huxhorn <jh...@googlemail.com>.
On 19.09.2011, at 01:29, Ralph Goers wrote:

> 
> On Sep 18, 2011, at 3:01 PM, Joern Huxhorn wrote:
> 
>> Sorry, I was confused and mixed something up...
>> 
>> I *planned* to implement a thread-specific sequence number but never did so. I also considered logging the ThreadGroup-hierarchy but didn't do so, yet, because of the expected performance impact.
>> 
>> Which reminds me, completely off-topic, of another idea concerning a custom Message implementation:
>> A ThreadDumpMessage that would not get any parameter at all and would consist of a ThreadDump if it is actually logged, including the ThreadGroup info etc..
>> This would have helped me immensely in the past. Instead, I had to trigger thread dumps via SIG_QUIT at a random points of execution.
>> 
>> Such a Message wouldn't be used in production under normal circumstances but could be enabled in case of strange concurrency issues...
> 
> I added it, but as I said, I wish I knew how to include the locks. 
> 
> FWIW, I could have used this 2 days ago when we were trying to debug just such a concurrency issue.
> 

I think http://download.oracle.com/javase/6/docs/api/java/lang/management/ThreadMXBean.html could be what you are looking for. 
Haven't given it a try, yet.

Joern.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 18, 2011, at 3:01 PM, Joern Huxhorn wrote:

> Sorry, I was confused and mixed something up...
> 
> I *planned* to implement a thread-specific sequence number but never did so. I also considered logging the ThreadGroup-hierarchy but didn't do so, yet, because of the expected performance impact.
> 
> Which reminds me, completely off-topic, of another idea concerning a custom Message implementation:
> A ThreadDumpMessage that would not get any parameter at all and would consist of a ThreadDump if it is actually logged, including the ThreadGroup info etc..
> This would have helped me immensely in the past. Instead, I had to trigger thread dumps via SIG_QUIT at a random points of execution.
> 
> Such a Message wouldn't be used in production under normal circumstances but could be enabled in case of strange concurrency issues...

I added it, but as I said, I wish I knew how to include the locks. 

FWIW, I could have used this 2 days ago when we were trying to debug just such a concurrency issue.

Ralph


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
That looks pretty easy to do. However, I'd prefer that the stack trace also show locks held just as the JVM stack trace does. I don't know how to do that. Do you?

Ralph

On Sep 18, 2011, at 3:01 PM, Joern Huxhorn wrote:

> Sorry, I was confused and mixed something up...
> 
> I *planned* to implement a thread-specific sequence number but never did so. I also considered logging the ThreadGroup-hierarchy but didn't do so, yet, because of the expected performance impact.
> 
> Which reminds me, completely off-topic, of another idea concerning a custom Message implementation:
> A ThreadDumpMessage that would not get any parameter at all and would consist of a ThreadDump if it is actually logged, including the ThreadGroup info etc..
> This would have helped me immensely in the past. Instead, I had to trigger thread dumps via SIG_QUIT at a random points of execution.
> 
> Such a Message wouldn't be used in production under normal circumstances but could be enabled in case of strange concurrency issues...
> 
> Joern.
> 
> On 18.09.2011, at 17:44, Scott Deboy wrote:
> 
>> Chainsaw does a similar thing by adding event properties when the event is received. It does this regardless of which Receiver received the event.
>> 
>> 
>> On Sep 18, 2011, at 4:54 AM, Joern Huxhorn <jh...@googlemail.com> wrote:
>> 
>>> 
>>> On 17.09.2011, at 23:42, Ralph Goers wrote:
>>> 
>>>> 
>>>> On Sep 17, 2011, at 1:43 PM, Joern Huxhorn wrote:
>>>> 
>>>>> 
>>>>> On 17.09.2011, at 21:26, Ralph Goers wrote:
>>>>> 
>>>>>> 
>>>>>> On Sep 17, 2011, at 11:40 AM, Joern Huxhorn wrote:
>>>>>> 
>>>>>>> 
>>>>>>> On 17.09.2011, at 18:47, John Vasileff wrote:
>>>>>>> 
>>>>>>>> 
>>>>>>>> On Sep 17, 2011, at 8:53 AM, Joern Huxhorn wrote:
>>>>>>>> 
>>>>>>>> Interesting point on serialization.  When would you see serialization happening?  Is this primarily for appenders?
>>>>>>>> 
>>>>>>> 
>>>>>>> SocketAppender is using serialization. Since I'm the author of Lilith ( http://lilith.huxhorn.de/ ) I tend to focus on stuff like that.
>>>>>> 
>>>>>> Actually, in Log4j 2.0 SocketAppender uses a Layout. The default Layout is SerializedLayout. If you want to use a LillithLayout you would be free to do so.
>>>>>> 
>>>>>>> 
>>>>>>> This is also the reason for the differentiation between the Message instance and the (laziliy) formatted  message string. A SocketAppender does not have any need for a formatted message. It is perfectly valid to skip the formatting entirely and simply transmit the message pattern and the message parameters (as Strings) to safe some CPU in the logged application.
>>>>>> 
>>>>>> I disagree. The SocketAppender should be able to interact with something that accepts Thrift, Avro, Hession or other serialization protocols or even the RFC 5424 format.  However, in cases where the event is serialized into a format where the LogEvent will be recreated on the other side of the socket connection, I agree that formatting the message on the sender's side is not required.
>>>>> 
>>>>> Your SocketAppender is obviously much improved compared to the Logback one. Having the actual serialization mechanism pluggable is a very good idea.
>>>>> Nevertheless, I assume that simple serialization would be the "reference implementation". I'd, of course, hook in my protobuf implementation...
>>>> 
>>>> If you provide a ProtobufLayout I'd happily include it - although I'd make the protobuf artifacts optional dependencies as I did for Flume.
>>> 
>>> Well, I could give you my protobuf but I'm not sure if it makes sense to add it to Log4J directly.
>>> 
>>> It contains more (optional) fields than Log4J will provide, partially since populating those fields has a performance impact. JUL has an event id by Thread but providing them would require ThreadLocal handling of the counter, i.e. reduces performance for very little additional info. Who would really use this information?
>>> I keep those infos in Lilith so it can import/receive events lossless but I don't think that Log4J should support them.
>>> 
>>> So it's probably best to keep this out of the Log4J codebase. If we add it then we'd have to coordinate future extension. If we leave it out as a third-party implementation of the SocketAppender layout then I can just change it as needed.
>>> 
>>> Joern.
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>>> 
>> 
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>> 
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Scott Deboy <sc...@gmail.com>.
It seems that log sanitization/addition of properties requires mutability at
some level.  Maybe it's a matter of having the mechanism needing to modify
properties tell the framework which attributes it plans on
modifying...but...it is reasonable to expect throwables to be changed after
they are generated (cutting out sensitive parts of the throwable), and for
messages to be changed (passwords replaced).  Properties, as I mentioned
previously, are really useful (it may make sense for a file-based appender
to define hostname and application properties, just like the network-based
appenders do).

Scott

On Fri, Sep 23, 2011 at 3:05 PM, John Vasileff <jo...@gmail.com> wrote:

> On Sep 23, 2011, at 3:37 AM, Ralph Goers wrote:
>
> >
> > On Sep 22, 2011, at 10:16 PM, Curt Arnold wrote:
> >
> >> Been lurking and watching the thread, wanted to throw some comments out
> without fully following the thread. Take everything with a grain of salt.
> >
> > Why? Your input is just as valuable as everyone else's.
> >
> >>
> >> log4j 1.2's AsyncAppender does a bit of this by calling all sorts of
> methods to force the lazy initialization of the event prior to the event
> being queued for processing by the worker thread. This can result in a lot
> of unnecessary work on the calling thread copying things like the MDC that
> might but might not be used in the eventual message formatting.
> >
> > For some reason I haven't gotten around to the AsyncAppender.  I'm afraid
> some copying of data when generating the LogEvent is inevitable.
> >
> >>
> >> Performing the rendering of the message on the calling thread is also
> not desirable since things like formatting floating point numbers can be
> surprisingly expensive.
> >
> > One advantage of the Message interface is that it can provide information
> that can help determine when it should be rendered. For example, in addition
> to the initialize method John proposed for the DeferredMessage it could also
> indicate when it should be deferred to.  Of course, Messages never need to
> format themselves until getFormattedMessage is called.
> >
> >>
> >> In some of my earlier design experiments, I was very fond of having the
> formatter/layout object supporting a two phase approach where the layout had
> an opportunity to "extract" from the logging event on the calling thread and
> then process the extracted information later on the worker thread. The
> extraction method would be responsible to assemble the information that it
> needed into an arbitrary immutable object that would be passed blindly by
> the framework to the formatting phase at the proper time. The implementation
> had the choice of whether it wanted to render all the way to String on the
> calling thread (say if it were cheap) on do the minimum to get immutable
> objects in the calling thread and do all the heavy lifting on the worker
> thread.
> >
> > I'm not sure I see the benefit of creating another object. You still need
> the LogEvent. Most of the work to insure the LogEvent can be passed to
> another thread really needs to be done anyway. Currently the constructor
> copies the MDC and NDC and a ThrowableProxy is constructed if a Throwable is
> present. About the only things that aren't being done then is the setting of
> the caller's StackTraceElement and setting the name of the current thread.
>  It is a simple matter to have the AsyncAppender cause those to be set.
> >
> > FWIW, the LogEvent should be immutable from the perspective of anything
> using it. Since LogEvent is an interface and only exposes get methods this
> would be true, except that getContextMap and getContextStack don't say they
> return unmodifiable objects and they implementation isn't returning
> immutable objects. They should.
> >
> >>
> >> Without getting the layout participating, you almost will be doing
> unnecessary work on the calling thread.
> >
> > I don't necessarily disagree with this part. For example, the Converters
> that deal with the caller's location could call LogEvent.getSource during
> the first call to make sure the required information in the LogEvent is
> captured. Of course, they would call that same method during the rendering
> but that second call would be very inexpensive.
> >
> >>
> >> I fleshed this approach out several years ago at
> https://svn.apache.org/repos/asf/logging/sandbox/experimental/pattern-layoutif anyone wants to take a look for ideas.
> >
> > I'll take a look at this.
> >
> > Ralph
> >
>
>
> While this doesn't address all of the points, a few thoughts:
>
> As Joern has pointed out, mutability is at odds with asynchronous logging.
>  The link he provided elsewhere:
> http://techblog.appnexus.com/2011/webkit-chrome-safari-console-log-bug/
>
> So some of the work really cannot be deferred.  But, since many params will
> be immutable anyway, ParameterizedMessage and others could create an
> immutable Object[] instead of a String[] as is currently done.  This would
> safely delay toString for all standard immutable types (i.e. no float
> conversions in the original thread).  For some Message types this is really
> essential as they may need access to the original Floats, Integers, Longs,
> etc. to perform proper formatting, for example, a java.util.Formatter
> message type.
>
>
> https://github.com/jvasileff/slf4j/blob/topic-jdk5-varargs/slf4j-ext/src/main/java/org/slf4j/ext/JUFMessage.java
>
>
> John
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>
>

Re: log4j2 parameterized msg with throwable

Posted by John Vasileff <jo...@gmail.com>.
On Sep 23, 2011, at 3:37 AM, Ralph Goers wrote:

> 
> On Sep 22, 2011, at 10:16 PM, Curt Arnold wrote:
> 
>> Been lurking and watching the thread, wanted to throw some comments out without fully following the thread. Take everything with a grain of salt.
> 
> Why? Your input is just as valuable as everyone else's.
> 
>> 
>> log4j 1.2's AsyncAppender does a bit of this by calling all sorts of methods to force the lazy initialization of the event prior to the event being queued for processing by the worker thread. This can result in a lot of unnecessary work on the calling thread copying things like the MDC that might but might not be used in the eventual message formatting.
> 
> For some reason I haven't gotten around to the AsyncAppender.  I'm afraid some copying of data when generating the LogEvent is inevitable. 
> 
>> 
>> Performing the rendering of the message on the calling thread is also not desirable since things like formatting floating point numbers can be surprisingly expensive.
> 
> One advantage of the Message interface is that it can provide information that can help determine when it should be rendered. For example, in addition to the initialize method John proposed for the DeferredMessage it could also indicate when it should be deferred to.  Of course, Messages never need to format themselves until getFormattedMessage is called.
> 
>> 
>> In some of my earlier design experiments, I was very fond of having the formatter/layout object supporting a two phase approach where the layout had an opportunity to "extract" from the logging event on the calling thread and then process the extracted information later on the worker thread. The extraction method would be responsible to assemble the information that it needed into an arbitrary immutable object that would be passed blindly by the framework to the formatting phase at the proper time. The implementation had the choice of whether it wanted to render all the way to String on the calling thread (say if it were cheap) on do the minimum to get immutable objects in the calling thread and do all the heavy lifting on the worker thread.
> 
> I'm not sure I see the benefit of creating another object. You still need the LogEvent. Most of the work to insure the LogEvent can be passed to another thread really needs to be done anyway. Currently the constructor copies the MDC and NDC and a ThrowableProxy is constructed if a Throwable is present. About the only things that aren't being done then is the setting of the caller's StackTraceElement and setting the name of the current thread.  It is a simple matter to have the AsyncAppender cause those to be set.  
> 
> FWIW, the LogEvent should be immutable from the perspective of anything using it. Since LogEvent is an interface and only exposes get methods this would be true, except that getContextMap and getContextStack don't say they return unmodifiable objects and they implementation isn't returning immutable objects. They should.
> 
>> 
>> Without getting the layout participating, you almost will be doing unnecessary work on the calling thread.
> 
> I don't necessarily disagree with this part. For example, the Converters that deal with the caller's location could call LogEvent.getSource during the first call to make sure the required information in the LogEvent is captured. Of course, they would call that same method during the rendering but that second call would be very inexpensive.
> 
>> 
>> I fleshed this approach out several years ago at https://svn.apache.org/repos/asf/logging/sandbox/experimental/pattern-layout if anyone wants to take a look for ideas.
> 
> I'll take a look at this.  
> 
> Ralph
> 


While this doesn't address all of the points, a few thoughts:

As Joern has pointed out, mutability is at odds with asynchronous logging.  The link he provided elsewhere: http://techblog.appnexus.com/2011/webkit-chrome-safari-console-log-bug/

So some of the work really cannot be deferred.  But, since many params will be immutable anyway, ParameterizedMessage and others could create an immutable Object[] instead of a String[] as is currently done.  This would safely delay toString for all standard immutable types (i.e. no float conversions in the original thread).  For some Message types this is really essential as they may need access to the original Floats, Integers, Longs, etc. to perform proper formatting, for example, a java.util.Formatter message type.

https://github.com/jvasileff/slf4j/blob/topic-jdk5-varargs/slf4j-ext/src/main/java/org/slf4j/ext/JUFMessage.java


John
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Scott Deboy <sc...@gmail.com>.
Extras.   I use them to build properties from a Map, add fixed  
properties to all events coming off the appender. I could see people  
using it to sanitize thread names,parts of thowables or messages as  
well.

Scott



On Sep 23, 2011, at 7:33 AM, Ralph Goers <ra...@dslextreme.com>  
wrote:

> Where are those located?
>
> Ralph
>
> On Sep 23, 2011, at 7:29 AM, Scott Deboy wrote:
>
>> Can you look at rewriteappender and rewritepolicy will fit in?   
>> Ability to modify the event message and add properties and possibly  
>> anything else via configuration.
>>
>>
>>
>> On Sep 23, 2011, at 12:37 AM, Ralph Goers  
>> <ra...@dslextreme.com> wrote:
>>
>>>
>>> On Sep 22, 2011, at 10:16 PM, Curt Arnold wrote:
>>>
>>>> Been lurking and watching the thread, wanted to throw some  
>>>> comments out without fully following the thread. Take everything  
>>>> with a grain of salt.
>>>
>>> Why? Your input is just as valuable as everyone else's.
>>>
>>>>
>>>> log4j 1.2's AsyncAppender does a bit of this by calling all sorts  
>>>> of methods to force the lazy initialization of the event prior to  
>>>> the event being queued for processing by the worker thread. This  
>>>> can result in a lot of unnecessary work on the calling thread  
>>>> copying things like the MDC that might but might not be used in  
>>>> the eventual message formatting.
>>>
>>> For some reason I haven't gotten around to the AsyncAppender.  I'm  
>>> afraid some copying of data when generating the LogEvent is  
>>> inevitable.
>>>
>>>>
>>>> Performing the rendering of the message on the calling thread is  
>>>> also not desirable since things like formatting floating point  
>>>> numbers can be surprisingly expensive.
>>>
>>> One advantage of the Message interface is that it can provide  
>>> information that can help determine when it should be rendered.  
>>> For example, in addition to the initialize method John proposed  
>>> for the DeferredMessage it could also indicate when it should be  
>>> deferred to.  Of course, Messages never need to format themselves  
>>> until getFormattedMessage is called.
>>>
>>>>
>>>> In some of my earlier design experiments, I was very fond of  
>>>> having the formatter/layout object supporting a two phase  
>>>> approach where the layout had an opportunity to "extract" from  
>>>> the logging event on the calling thread and then process the  
>>>> extracted information later on the worker thread. The extraction  
>>>> method would be responsible to assemble the information that it  
>>>> needed into an arbitrary immutable object that would be passed  
>>>> blindly by the framework to the formatting phase at the proper  
>>>> time. The implementation had the choice of whether it wanted to  
>>>> render all the way to String on the calling thread (say if it  
>>>> were cheap) on do the minimum to get immutable objects in the  
>>>> calling thread and do all the heavy lifting on the worker thread.
>>>
>>> I'm not sure I see the benefit of creating another object. You  
>>> still need the LogEvent. Most of the work to insure the LogEvent  
>>> can be passed to another thread really needs to be done anyway.  
>>> Currently the constructor copies the MDC and NDC and a  
>>> ThrowableProxy is constructed if a Throwable is present. About the  
>>> only things that aren't being done then is the setting of the  
>>> caller's StackTraceElement and setting the name of the current  
>>> thread.  It is a simple matter to have the AsyncAppender cause  
>>> those to be set.
>>>
>>> FWIW, the LogEvent should be immutable from the perspective of  
>>> anything using it. Since LogEvent is an interface and only exposes  
>>> get methods this would be true, except that getContextMap and  
>>> getContextStack don't say they return unmodifiable objects and  
>>> they implementation isn't returning immutable objects. They should.
>>>
>>>>
>>>> Without getting the layout participating, you almost will be  
>>>> doing unnecessary work on the calling thread.
>>>
>>> I don't necessarily disagree with this part. For example, the  
>>> Converters that deal with the caller's location could call  
>>> LogEvent.getSource during the first call to make sure the required  
>>> information in the LogEvent is captured. Of course, they would  
>>> call that same method during the rendering but that second call  
>>> would be very inexpensive.
>>>
>>>>
>>>> I fleshed this approach out several years ago at https://svn.apache.org/repos/asf/logging/sandbox/experimental/pattern-layout 
>>>>  if anyone wants to take a look for ideas.
>>>
>>> I'll take a look at this.
>>>
>>> Ralph
>>>
>>>
>>> --- 
>>> ------------------------------------------------------------------
>>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
Where are those located?

Ralph

On Sep 23, 2011, at 7:29 AM, Scott Deboy wrote:

> Can you look at rewriteappender and rewritepolicy will fit in?  Ability to modify the event message and add properties and possibly anything else via configuration.
> 
> 
> 
> On Sep 23, 2011, at 12:37 AM, Ralph Goers <ra...@dslextreme.com> wrote:
> 
>> 
>> On Sep 22, 2011, at 10:16 PM, Curt Arnold wrote:
>> 
>>> Been lurking and watching the thread, wanted to throw some comments out without fully following the thread. Take everything with a grain of salt.
>> 
>> Why? Your input is just as valuable as everyone else's.
>> 
>>> 
>>> log4j 1.2's AsyncAppender does a bit of this by calling all sorts of methods to force the lazy initialization of the event prior to the event being queued for processing by the worker thread. This can result in a lot of unnecessary work on the calling thread copying things like the MDC that might but might not be used in the eventual message formatting.
>> 
>> For some reason I haven't gotten around to the AsyncAppender.  I'm afraid some copying of data when generating the LogEvent is inevitable.
>> 
>>> 
>>> Performing the rendering of the message on the calling thread is also not desirable since things like formatting floating point numbers can be surprisingly expensive.
>> 
>> One advantage of the Message interface is that it can provide information that can help determine when it should be rendered. For example, in addition to the initialize method John proposed for the DeferredMessage it could also indicate when it should be deferred to.  Of course, Messages never need to format themselves until getFormattedMessage is called.
>> 
>>> 
>>> In some of my earlier design experiments, I was very fond of having the formatter/layout object supporting a two phase approach where the layout had an opportunity to "extract" from the logging event on the calling thread and then process the extracted information later on the worker thread. The extraction method would be responsible to assemble the information that it needed into an arbitrary immutable object that would be passed blindly by the framework to the formatting phase at the proper time. The implementation had the choice of whether it wanted to render all the way to String on the calling thread (say if it were cheap) on do the minimum to get immutable objects in the calling thread and do all the heavy lifting on the worker thread.
>> 
>> I'm not sure I see the benefit of creating another object. You still need the LogEvent. Most of the work to insure the LogEvent can be passed to another thread really needs to be done anyway. Currently the constructor copies the MDC and NDC and a ThrowableProxy is constructed if a Throwable is present. About the only things that aren't being done then is the setting of the caller's StackTraceElement and setting the name of the current thread.  It is a simple matter to have the AsyncAppender cause those to be set.
>> 
>> FWIW, the LogEvent should be immutable from the perspective of anything using it. Since LogEvent is an interface and only exposes get methods this would be true, except that getContextMap and getContextStack don't say they return unmodifiable objects and they implementation isn't returning immutable objects. They should.
>> 
>>> 
>>> Without getting the layout participating, you almost will be doing unnecessary work on the calling thread.
>> 
>> I don't necessarily disagree with this part. For example, the Converters that deal with the caller's location could call LogEvent.getSource during the first call to make sure the required information in the LogEvent is captured. Of course, they would call that same method during the rendering but that second call would be very inexpensive.
>> 
>>> 
>>> I fleshed this approach out several years ago at https://svn.apache.org/repos/asf/logging/sandbox/experimental/pattern-layout if anyone wants to take a look for ideas.
>> 
>> I'll take a look at this.
>> 
>> Ralph
>> 
>> 
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Scott Deboy <sc...@gmail.com>.
Can you look at rewriteappender and rewritepolicy will fit in?   
Ability to modify the event message and add properties and possibly  
anything else via configuration.



On Sep 23, 2011, at 12:37 AM, Ralph Goers <ra...@dslextreme.com>  
wrote:

>
> On Sep 22, 2011, at 10:16 PM, Curt Arnold wrote:
>
>> Been lurking and watching the thread, wanted to throw some comments  
>> out without fully following the thread. Take everything with a  
>> grain of salt.
>
> Why? Your input is just as valuable as everyone else's.
>
>>
>> log4j 1.2's AsyncAppender does a bit of this by calling all sorts  
>> of methods to force the lazy initialization of the event prior to  
>> the event being queued for processing by the worker thread. This  
>> can result in a lot of unnecessary work on the calling thread  
>> copying things like the MDC that might but might not be used in the  
>> eventual message formatting.
>
> For some reason I haven't gotten around to the AsyncAppender.  I'm  
> afraid some copying of data when generating the LogEvent is  
> inevitable.
>
>>
>> Performing the rendering of the message on the calling thread is  
>> also not desirable since things like formatting floating point  
>> numbers can be surprisingly expensive.
>
> One advantage of the Message interface is that it can provide  
> information that can help determine when it should be rendered. For  
> example, in addition to the initialize method John proposed for the  
> DeferredMessage it could also indicate when it should be deferred  
> to.  Of course, Messages never need to format themselves until  
> getFormattedMessage is called.
>
>>
>> In some of my earlier design experiments, I was very fond of having  
>> the formatter/layout object supporting a two phase approach where  
>> the layout had an opportunity to "extract" from the logging event  
>> on the calling thread and then process the extracted information  
>> later on the worker thread. The extraction method would be  
>> responsible to assemble the information that it needed into an  
>> arbitrary immutable object that would be passed blindly by the  
>> framework to the formatting phase at the proper time. The  
>> implementation had the choice of whether it wanted to render all  
>> the way to String on the calling thread (say if it were cheap) on  
>> do the minimum to get immutable objects in the calling thread and  
>> do all the heavy lifting on the worker thread.
>
> I'm not sure I see the benefit of creating another object. You still  
> need the LogEvent. Most of the work to insure the LogEvent can be  
> passed to another thread really needs to be done anyway. Currently  
> the constructor copies the MDC and NDC and a ThrowableProxy is  
> constructed if a Throwable is present. About the only things that  
> aren't being done then is the setting of the caller's  
> StackTraceElement and setting the name of the current thread.  It is  
> a simple matter to have the AsyncAppender cause those to be set.
>
> FWIW, the LogEvent should be immutable from the perspective of  
> anything using it. Since LogEvent is an interface and only exposes  
> get methods this would be true, except that getContextMap and  
> getContextStack don't say they return unmodifiable objects and they  
> implementation isn't returning immutable objects. They should.
>
>>
>> Without getting the layout participating, you almost will be doing  
>> unnecessary work on the calling thread.
>
> I don't necessarily disagree with this part. For example, the  
> Converters that deal with the caller's location could call  
> LogEvent.getSource during the first call to make sure the required  
> information in the LogEvent is captured. Of course, they would call  
> that same method during the rendering but that second call would be  
> very inexpensive.
>
>>
>> I fleshed this approach out several years ago at https://svn.apache.org/repos/asf/logging/sandbox/experimental/pattern-layout 
>>  if anyone wants to take a look for ideas.
>
> I'll take a look at this.
>
> Ralph
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 22, 2011, at 10:16 PM, Curt Arnold wrote:

> Been lurking and watching the thread, wanted to throw some comments out without fully following the thread. Take everything with a grain of salt.

Why? Your input is just as valuable as everyone else's.

> 
> log4j 1.2's AsyncAppender does a bit of this by calling all sorts of methods to force the lazy initialization of the event prior to the event being queued for processing by the worker thread. This can result in a lot of unnecessary work on the calling thread copying things like the MDC that might but might not be used in the eventual message formatting.

For some reason I haven't gotten around to the AsyncAppender.  I'm afraid some copying of data when generating the LogEvent is inevitable. 

> 
> Performing the rendering of the message on the calling thread is also not desirable since things like formatting floating point numbers can be surprisingly expensive.

One advantage of the Message interface is that it can provide information that can help determine when it should be rendered. For example, in addition to the initialize method John proposed for the DeferredMessage it could also indicate when it should be deferred to.  Of course, Messages never need to format themselves until getFormattedMessage is called.

> 
> In some of my earlier design experiments, I was very fond of having the formatter/layout object supporting a two phase approach where the layout had an opportunity to "extract" from the logging event on the calling thread and then process the extracted information later on the worker thread. The extraction method would be responsible to assemble the information that it needed into an arbitrary immutable object that would be passed blindly by the framework to the formatting phase at the proper time. The implementation had the choice of whether it wanted to render all the way to String on the calling thread (say if it were cheap) on do the minimum to get immutable objects in the calling thread and do all the heavy lifting on the worker thread.

I'm not sure I see the benefit of creating another object. You still need the LogEvent. Most of the work to insure the LogEvent can be passed to another thread really needs to be done anyway. Currently the constructor copies the MDC and NDC and a ThrowableProxy is constructed if a Throwable is present. About the only things that aren't being done then is the setting of the caller's StackTraceElement and setting the name of the current thread.  It is a simple matter to have the AsyncAppender cause those to be set.  

FWIW, the LogEvent should be immutable from the perspective of anything using it. Since LogEvent is an interface and only exposes get methods this would be true, except that getContextMap and getContextStack don't say they return unmodifiable objects and they implementation isn't returning immutable objects. They should.

> 
> Without getting the layout participating, you almost will be doing unnecessary work on the calling thread.

I don't necessarily disagree with this part. For example, the Converters that deal with the caller's location could call LogEvent.getSource during the first call to make sure the required information in the LogEvent is captured. Of course, they would call that same method during the rendering but that second call would be very inexpensive.

> 
> I fleshed this approach out several years ago at https://svn.apache.org/repos/asf/logging/sandbox/experimental/pattern-layout if anyone wants to take a look for ideas.

I'll take a look at this.  

Ralph


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Curt Arnold <ca...@apache.org>.
Been lurking and watching the thread, wanted to throw some comments out without fully following the thread. Take everything with a grain of salt.

log4j 1.2's AsyncAppender does a bit of this by calling all sorts of methods to force the lazy initialization of the event prior to the event being queued for processing by the worker thread. This can result in a lot of unnecessary work on the calling thread copying things like the MDC that might but might not be used in the eventual message formatting.

Performing the rendering of the message on the calling thread is also not desirable since things like formatting floating point numbers can be surprisingly expensive.

In some of my earlier design experiments, I was very fond of having the formatter/layout object supporting a two phase approach where the layout had an opportunity to "extract" from the logging event on the calling thread and then process the extracted information later on the worker thread. The extraction method would be responsible to assemble the information that it needed into an arbitrary immutable object that would be passed blindly by the framework to the formatting phase at the proper time. The implementation had the choice of whether it wanted to render all the way to String on the calling thread (say if it were cheap) on do the minimum to get immutable objects in the calling thread and do all the heavy lifting on the worker thread.

Without getting the layout participating, you almost will be doing unnecessary work on the calling thread.

I fleshed this approach out several years ago at https://svn.apache.org/repos/asf/logging/sandbox/experimental/pattern-layout if anyone wants to take a look for ideas.




---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by "ralph.goers @dslextreme.com" <ra...@dslextreme.com>.
That actually is an interesting concept.  I can picture registering a
ThreadDumpMessage along with a Filter and when the Filter matches the
Message gets logged. The only problem with that is I'm not sure I'd want to
include that in the logging system itself since it could only be evaluated
as log messages flow through.

Ralph


On Tue, Sep 20, 2011 at 9:37 AM, John Vasileff <jo...@gmail.com> wrote:

>
> On Sep 20, 2011, at 2:36 AM, Ralph Goers wrote:
>
> >
> > On Sep 19, 2011, at 6:39 PM, John Vasileff wrote:
> >
> >>
> >> package org.apache.logging.log4j.message;
> >>
> >> /**
> >> * A Message that supports lazy initialization.
> >> */
> >> public interface InitializingMessage extends Message {
> >>
> >> /**
> >>  * Lazily perform expensive initialization tasks that would otherwise
> occur in
> >>  * the constructor. For example, cloning mutable message content or
> gathering
> >>  * data to be logged. Loggers are required to call this method
> immediately
> >>  * after determining this Message is likely to be logged based on the
> log
> >>  * Level and Marker, and before returning from the log method (i.e.
> >>  * trace(message)). The Logger will not call initialize() if no logging
> will be
> >>  * performed based on Level and Marker.
> >>  *
> >>  * Initialization must be performed before returning from the first call
> to this
> >>  * method. Subsequent calls must be no-ops.
> >>  *
> >>  * @return This Message.
> >>  */
> >> Message initialize();
> >>
> >> }
> >
> > How would you feel about calling it DeferredMessage?
> >
> > Ralph
>
> I think that would work.
>
> The one problem I see is that it could imply that Message delivery is
> deferred.  That is, the Message would be held by the logging system until
> logging is triggered by some future event.  DeferredInitializationMessage
> would be more clear, but is rather verbose.
>
>
> John
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>
>

Re: log4j2 parameterized msg with throwable

Posted by John Vasileff <jo...@gmail.com>.
On Sep 20, 2011, at 2:36 AM, Ralph Goers wrote:

> 
> On Sep 19, 2011, at 6:39 PM, John Vasileff wrote:
> 
>> 
>> package org.apache.logging.log4j.message;
>> 
>> /**
>> * A Message that supports lazy initialization.
>> */
>> public interface InitializingMessage extends Message {
>> 
>> /**
>>  * Lazily perform expensive initialization tasks that would otherwise occur in
>>  * the constructor. For example, cloning mutable message content or gathering
>>  * data to be logged. Loggers are required to call this method immediately
>>  * after determining this Message is likely to be logged based on the log
>>  * Level and Marker, and before returning from the log method (i.e.
>>  * trace(message)). The Logger will not call initialize() if no logging will be
>>  * performed based on Level and Marker.
>>  * 
>>  * Initialization must be performed before returning from the first call to this
>>  * method. Subsequent calls must be no-ops.
>>  * 
>>  * @return This Message.
>>  */
>> Message initialize();
>> 
>> }
> 
> How would you feel about calling it DeferredMessage?
> 
> Ralph

I think that would work.

The one problem I see is that it could imply that Message delivery is deferred.  That is, the Message would be held by the logging system until logging is triggered by some future event.  DeferredInitializationMessage would be more clear, but is rather verbose.


John
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 19, 2011, at 6:39 PM, John Vasileff wrote:

> 
> package org.apache.logging.log4j.message;
> 
> /**
> * A Message that supports lazy initialization.
> */
> public interface InitializingMessage extends Message {
> 
>  /**
>   * Lazily perform expensive initialization tasks that would otherwise occur in
>   * the constructor. For example, cloning mutable message content or gathering
>   * data to be logged. Loggers are required to call this method immediately
>   * after determining this Message is likely to be logged based on the log
>   * Level and Marker, and before returning from the log method (i.e.
>   * trace(message)). The Logger will not call initialize() if no logging will be
>   * performed based on Level and Marker.
>   * 
>   * Initialization must be performed before returning from the first call to this
>   * method. Subsequent calls must be no-ops.
>   * 
>   * @return This Message.
>   */
>  Message initialize();
> 
> }

How would you feel about calling it DeferredMessage?

Ralph
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by John Vasileff <jo...@gmail.com>.
On Sep 19, 2011, at 8:51 PM, Ralph Goers wrote:

> 
> On Sep 19, 2011, at 3:19 PM, Joern Huxhorn wrote:
> 
>> 
>> On 19.09.2011, at 22:09, ralph.goers @dslextreme.com wrote:
>> 
>>> 
>>> 
>>> On Mon, Sep 19, 2011 at 1:07 PM, ralph.goers @dslextreme.com <ra...@dslextreme.com> wrote:
>>> 
>>> 
>>> On Mon, Sep 19, 2011 at 10:07 AM, John Vasileff <jo...@gmail.com> wrote:
>>> 
>>> What do you think about an optional LazyRenderMessage interface (I'm sure there is a better name for this) that could be used by Message types that have expensive constructers?
>>> 
>>> interface LazyRenderMessage {
>>> void render();
>>> }
>>> 
>>> The logger would call render() immediately after checking isEnabled for level and marker.  So, this should not affect serialization - the object will either be fully constructed or discarded right away.
>>> 
>>> This would allow ThreadDumpMessage Thread.getAllStackTraces() work to be avoided unless logging will actually occur (or is likely to occur in the case of complex filters).
>>> 
>>> The benefit of course is that trace(THREAD_DUMP_MARKER, new ThreadDumpMessage()) could be left in production code without if isTraceEnabled(...) { ... }, and with very little overhead - creating a short lived object that does nothing in the constructor is pretty cheap these days.
>>> 
>>> This would also help for Message types like ParameterizedMessage to avoid parseArguments(arguments) when they are created by application code.
>>> 
>>> I see some merit in this idea. But you are right, it really needs a better name.
>>> 
>>> One other point, though, is that there should always be a constructor that allows immediate rendering. I could easily see the ThreadDumpMessage being used for other purposes and never being passed to a logger. For example, I could create two ThreadDumpMessages at slightly different points in time and then only print the differences between them.
>>> 
>> 
>> But the whole idea of the Message interface was the lazy evaluation of the expensive String creation with the suggestion to also cache those strings for reuse. Otherwise using toString() wouldn't make a big difference...
>> 
>> Printing the differences between two ThreadDumpMessages would be an additional functionality, of course. I guess that something like a populate() method filling in the stacktrace (separate from string creation) would make sense. That could be called automatically if it wasn't called explicitly before execution of getFormattedMessage()...
> 
> A ThreadDumpMessage pretty much has to capture all the data immediately or its usefulness would be quite limited. If you look at the way I implemented that class you will see it captures the thread information in the constructor. However, it doesn't actually build the formatted String until the first call to getFormattedMessage.  This is actually what you would want if one were to create a ThreadDumpDiffMessage. 
> 
> John's proposal is to have the ThreadDumpMessage constructor do nothing. The Thread data wouldn't be captured until the render method is called. You've basically said the same thing with regard to the populate method. Although my preference would be to have constructors that allow for both I guess I'd also be OK with having the populate/render/initialize method return the Message so that you could do 
> 
> ThreadDumpMessage msg = new ThreadDumpMessage.populate();
> 
> If Logger is going to call the populate method then it obviously has to check whether that has already been done.
> 
> Ralph
> 
> 

package org.apache.logging.log4j.message;

/**
 * A Message that supports lazy initialization.
 */
public interface InitializingMessage extends Message {

  /**
   * Lazily perform expensive initialization tasks that would otherwise occur in
   * the constructor. For example, cloning mutable message content or gathering
   * data to be logged. Loggers are required to call this method immediately
   * after determining this Message is likely to be logged based on the log
   * Level and Marker, and before returning from the log method (i.e.
   * trace(message)). The Logger will not call initialize() if no logging will be
   * performed based on Level and Marker.
   * 
   * Initialization must be performed before returning from the first call to this
   * method. Subsequent calls must be no-ops.
   * 
   * @return This Message.
   */
  Message initialize();

}

John
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 19, 2011, at 3:19 PM, Joern Huxhorn wrote:

> 
> On 19.09.2011, at 22:09, ralph.goers @dslextreme.com wrote:
> 
>> 
>> 
>> On Mon, Sep 19, 2011 at 1:07 PM, ralph.goers @dslextreme.com <ra...@dslextreme.com> wrote:
>> 
>> 
>> On Mon, Sep 19, 2011 at 10:07 AM, John Vasileff <jo...@gmail.com> wrote:
>> 
>> What do you think about an optional LazyRenderMessage interface (I'm sure there is a better name for this) that could be used by Message types that have expensive constructers?
>> 
>> interface LazyRenderMessage {
>>  void render();
>> }
>> 
>> The logger would call render() immediately after checking isEnabled for level and marker.  So, this should not affect serialization - the object will either be fully constructed or discarded right away.
>> 
>> This would allow ThreadDumpMessage Thread.getAllStackTraces() work to be avoided unless logging will actually occur (or is likely to occur in the case of complex filters).
>> 
>> The benefit of course is that trace(THREAD_DUMP_MARKER, new ThreadDumpMessage()) could be left in production code without if isTraceEnabled(...) { ... }, and with very little overhead - creating a short lived object that does nothing in the constructor is pretty cheap these days.
>> 
>> This would also help for Message types like ParameterizedMessage to avoid parseArguments(arguments) when they are created by application code.
>> 
>> I see some merit in this idea. But you are right, it really needs a better name.
>> 
>> One other point, though, is that there should always be a constructor that allows immediate rendering. I could easily see the ThreadDumpMessage being used for other purposes and never being passed to a logger. For example, I could create two ThreadDumpMessages at slightly different points in time and then only print the differences between them.
>> 
> 
> But the whole idea of the Message interface was the lazy evaluation of the expensive String creation with the suggestion to also cache those strings for reuse. Otherwise using toString() wouldn't make a big difference...
> 
> Printing the differences between two ThreadDumpMessages would be an additional functionality, of course. I guess that something like a populate() method filling in the stacktrace (separate from string creation) would make sense. That could be called automatically if it wasn't called explicitly before execution of getFormattedMessage()...

A ThreadDumpMessage pretty much has to capture all the data immediately or its usefulness would be quite limited. If you look at the way I implemented that class you will see it captures the thread information in the constructor. However, it doesn't actually build the formatted String until the first call to getFormattedMessage.  This is actually what you would want if one were to create a ThreadDumpDiffMessage. 

John's proposal is to have the ThreadDumpMessage constructor do nothing. The Thread data wouldn't be captured until the render method is called. You've basically said the same thing with regard to the populate method. Although my preference would be to have constructors that allow for both I guess I'd also be OK with having the populate/render/initialize method return the Message so that you could do 

ThreadDumpMessage msg = new ThreadDumpMessage.populate();

If Logger is going to call the populate method then it obviously has to check whether that has already been done.

Ralph




---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Joern Huxhorn <jh...@googlemail.com>.
On 19.09.2011, at 22:09, ralph.goers @dslextreme.com wrote:

> 
> 
> On Mon, Sep 19, 2011 at 1:07 PM, ralph.goers @dslextreme.com <ra...@dslextreme.com> wrote:
> 
> 
> On Mon, Sep 19, 2011 at 10:07 AM, John Vasileff <jo...@gmail.com> wrote:
> 
> What do you think about an optional LazyRenderMessage interface (I'm sure there is a better name for this) that could be used by Message types that have expensive constructers?
> 
> interface LazyRenderMessage {
>   void render();
> }
> 
> The logger would call render() immediately after checking isEnabled for level and marker.  So, this should not affect serialization - the object will either be fully constructed or discarded right away.
> 
> This would allow ThreadDumpMessage Thread.getAllStackTraces() work to be avoided unless logging will actually occur (or is likely to occur in the case of complex filters).
> 
> The benefit of course is that trace(THREAD_DUMP_MARKER, new ThreadDumpMessage()) could be left in production code without if isTraceEnabled(...) { ... }, and with very little overhead - creating a short lived object that does nothing in the constructor is pretty cheap these days.
> 
> This would also help for Message types like ParameterizedMessage to avoid parseArguments(arguments) when they are created by application code.
> 
> I see some merit in this idea. But you are right, it really needs a better name.
> 
> One other point, though, is that there should always be a constructor that allows immediate rendering. I could easily see the ThreadDumpMessage being used for other purposes and never being passed to a logger. For example, I could create two ThreadDumpMessages at slightly different points in time and then only print the differences between them.
> 

But the whole idea of the Message interface was the lazy evaluation of the expensive String creation with the suggestion to also cache those strings for reuse. Otherwise using toString() wouldn't make a big difference...

Printing the differences between two ThreadDumpMessages would be an additional functionality, of course. I guess that something like a populate() method filling in the stacktrace (separate from string creation) would make sense. That could be called automatically if it wasn't called explicitly before execution of getFormattedMessage()...

Joern.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by John Vasileff <jo...@gmail.com>.
On Sep 19, 2011, at 4:09 PM, ralph.goers @dslextreme.com wrote:

> 
> 
> On Mon, Sep 19, 2011 at 1:07 PM, ralph.goers @dslextreme.com <ra...@dslextreme.com> wrote:
> 
> 
> On Mon, Sep 19, 2011 at 10:07 AM, John Vasileff <jo...@gmail.com> wrote:
> 
> What do you think about an optional LazyRenderMessage interface (I'm sure there is a better name for this) that could be used by Message types that have expensive constructers?
> 
> interface LazyRenderMessage {
>   void render();
> }
> 
> The logger would call render() immediately after checking isEnabled for level and marker.  So, this should not affect serialization - the object will either be fully constructed or discarded right away.
> 
> This would allow ThreadDumpMessage Thread.getAllStackTraces() work to be avoided unless logging will actually occur (or is likely to occur in the case of complex filters).
> 
> The benefit of course is that trace(THREAD_DUMP_MARKER, new ThreadDumpMessage()) could be left in production code without if isTraceEnabled(...) { ... }, and with very little overhead - creating a short lived object that does nothing in the constructor is pretty cheap these days.
> 
> This would also help for Message types like ParameterizedMessage to avoid parseArguments(arguments) when they are created by application code.
> 
> I see some merit in this idea. But you are right, it really needs a better name.
> 
> One other point, though, is that there should always be a constructor that allows immediate rendering. I could easily see the ThreadDumpMessage being used for other purposes and never being passed to a logger. For example, I could create two ThreadDumpMessages at slightly different points in time and then only print the differences between them.
> 
> Ralph 

Good point.

new ThreadDumpMessage().render();

would work if documented in the javadocs for the constructor.  But I would hate to make things too complicated to bail out those too lazy to check isEnabled.  I don't have a strong opinion either way on whether this complicates things too much.  Maybe those that need to call render() will also pick up on the fact, and those that don't, don't need to.  Not sure.

As far as naming goes - I suppose it would take some effort to come up with something worse!  I have no good ideas.


John

Re: log4j2 parameterized msg with throwable

Posted by "ralph.goers @dslextreme.com" <ra...@dslextreme.com>.
On Mon, Sep 19, 2011 at 1:07 PM, ralph.goers @dslextreme.com <
ralph.goers@dslextreme.com> wrote:

>
>
> On Mon, Sep 19, 2011 at 10:07 AM, John Vasileff <jo...@gmail.com>wrote:
>
>>
>> What do you think about an optional LazyRenderMessage interface (I'm sure
>> there is a better name for this) that could be used by Message types that
>> have expensive constructers?
>>
>> interface LazyRenderMessage {
>>   void render();
>> }
>>
>> The logger would call render() immediately after checking isEnabled for
>> level and marker.  So, this should not affect serialization - the object
>> will either be fully constructed or discarded right away.
>>
>> This would allow ThreadDumpMessage Thread.getAllStackTraces() work to be
>> avoided unless logging will actually occur (or is likely to occur in the
>> case of complex filters).
>>
>> The benefit of course is that trace(THREAD_DUMP_MARKER, new
>> ThreadDumpMessage()) could be left in production code without if
>> isTraceEnabled(...) { ... }, and with very little overhead - creating a
>> short lived object that does nothing in the constructor is pretty cheap
>> these days.
>>
>> This would also help for Message types like ParameterizedMessage to avoid
>> parseArguments(arguments) when they are created by application code.
>>
>
> I see some merit in this idea. But you are right, it really needs a better
> name.
>
> One other point, though, is that there should always be a constructor that
allows immediate rendering. I could easily see the ThreadDumpMessage being
used for other purposes and never being passed to a logger. For example, I
could create two ThreadDumpMessages at slightly different points in time and
then only print the differences between them.

Ralph

Re: log4j2 parameterized msg with throwable

Posted by "ralph.goers @dslextreme.com" <ra...@dslextreme.com>.
On Mon, Sep 19, 2011 at 10:07 AM, John Vasileff <jo...@gmail.com>wrote:

>
> What do you think about an optional LazyRenderMessage interface (I'm sure
> there is a better name for this) that could be used by Message types that
> have expensive constructers?
>
> interface LazyRenderMessage {
>   void render();
> }
>
> The logger would call render() immediately after checking isEnabled for
> level and marker.  So, this should not affect serialization - the object
> will either be fully constructed or discarded right away.
>
> This would allow ThreadDumpMessage Thread.getAllStackTraces() work to be
> avoided unless logging will actually occur (or is likely to occur in the
> case of complex filters).
>
> The benefit of course is that trace(THREAD_DUMP_MARKER, new
> ThreadDumpMessage()) could be left in production code without if
> isTraceEnabled(...) { ... }, and with very little overhead - creating a
> short lived object that does nothing in the constructor is pretty cheap
> these days.
>
> This would also help for Message types like ParameterizedMessage to avoid
> parseArguments(arguments) when they are created by application code.
>

I see some merit in this idea. But you are right, it really needs a better
name.

Ralph

Re: log4j2 parameterized msg with throwable

Posted by John Vasileff <jo...@gmail.com>.
On Sep 18, 2011, at 6:01 PM, Joern Huxhorn wrote:

> Which reminds me, completely off-topic, of another idea concerning a custom Message implementation:
> A ThreadDumpMessage that would not get any parameter at all and would consist of a ThreadDump if it is actually logged, including the ThreadGroup info etc..
> This would have helped me immensely in the past. Instead, I had to trigger thread dumps via SIG_QUIT at a random points of execution.
> 
> Such a Message wouldn't be used in production under normal circumstances but could be enabled in case of strange concurrency issues...
> 
> Joern.
> 


What do you think about an optional LazyRenderMessage interface (I'm sure there is a better name for this) that could be used by Message types that have expensive constructers?

interface LazyRenderMessage {
   void render();
}

The logger would call render() immediately after checking isEnabled for level and marker.  So, this should not affect serialization - the object will either be fully constructed or discarded right away.

This would allow ThreadDumpMessage Thread.getAllStackTraces() work to be avoided unless logging will actually occur (or is likely to occur in the case of complex filters).

The benefit of course is that trace(THREAD_DUMP_MARKER, new ThreadDumpMessage()) could be left in production code without if isTraceEnabled(...) { ... }, and with very little overhead - creating a short lived object that does nothing in the constructor is pretty cheap these days.

This would also help for Message types like ParameterizedMessage to avoid parseArguments(arguments) when they are created by application code.


John
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Joern Huxhorn <jh...@googlemail.com>.
Sorry, I was confused and mixed something up...

I *planned* to implement a thread-specific sequence number but never did so. I also considered logging the ThreadGroup-hierarchy but didn't do so, yet, because of the expected performance impact.

Which reminds me, completely off-topic, of another idea concerning a custom Message implementation:
A ThreadDumpMessage that would not get any parameter at all and would consist of a ThreadDump if it is actually logged, including the ThreadGroup info etc..
This would have helped me immensely in the past. Instead, I had to trigger thread dumps via SIG_QUIT at a random points of execution.

Such a Message wouldn't be used in production under normal circumstances but could be enabled in case of strange concurrency issues...

Joern.

On 18.09.2011, at 17:44, Scott Deboy wrote:

> Chainsaw does a similar thing by adding event properties when the event is received. It does this regardless of which Receiver received the event.
> 
> 
> On Sep 18, 2011, at 4:54 AM, Joern Huxhorn <jh...@googlemail.com> wrote:
> 
>> 
>> On 17.09.2011, at 23:42, Ralph Goers wrote:
>> 
>>> 
>>> On Sep 17, 2011, at 1:43 PM, Joern Huxhorn wrote:
>>> 
>>>> 
>>>> On 17.09.2011, at 21:26, Ralph Goers wrote:
>>>> 
>>>>> 
>>>>> On Sep 17, 2011, at 11:40 AM, Joern Huxhorn wrote:
>>>>> 
>>>>>> 
>>>>>> On 17.09.2011, at 18:47, John Vasileff wrote:
>>>>>> 
>>>>>>> 
>>>>>>> On Sep 17, 2011, at 8:53 AM, Joern Huxhorn wrote:
>>>>>>> 
>>>>>>> Interesting point on serialization.  When would you see serialization happening?  Is this primarily for appenders?
>>>>>>> 
>>>>>> 
>>>>>> SocketAppender is using serialization. Since I'm the author of Lilith ( http://lilith.huxhorn.de/ ) I tend to focus on stuff like that.
>>>>> 
>>>>> Actually, in Log4j 2.0 SocketAppender uses a Layout. The default Layout is SerializedLayout. If you want to use a LillithLayout you would be free to do so.
>>>>> 
>>>>>> 
>>>>>> This is also the reason for the differentiation between the Message instance and the (laziliy) formatted  message string. A SocketAppender does not have any need for a formatted message. It is perfectly valid to skip the formatting entirely and simply transmit the message pattern and the message parameters (as Strings) to safe some CPU in the logged application.
>>>>> 
>>>>> I disagree. The SocketAppender should be able to interact with something that accepts Thrift, Avro, Hession or other serialization protocols or even the RFC 5424 format.  However, in cases where the event is serialized into a format where the LogEvent will be recreated on the other side of the socket connection, I agree that formatting the message on the sender's side is not required.
>>>> 
>>>> Your SocketAppender is obviously much improved compared to the Logback one. Having the actual serialization mechanism pluggable is a very good idea.
>>>> Nevertheless, I assume that simple serialization would be the "reference implementation". I'd, of course, hook in my protobuf implementation...
>>> 
>>> If you provide a ProtobufLayout I'd happily include it - although I'd make the protobuf artifacts optional dependencies as I did for Flume.
>> 
>> Well, I could give you my protobuf but I'm not sure if it makes sense to add it to Log4J directly.
>> 
>> It contains more (optional) fields than Log4J will provide, partially since populating those fields has a performance impact. JUL has an event id by Thread but providing them would require ThreadLocal handling of the counter, i.e. reduces performance for very little additional info. Who would really use this information?
>> I keep those infos in Lilith so it can import/receive events lossless but I don't think that Log4J should support them.
>> 
>> So it's probably best to keep this out of the Log4J codebase. If we add it then we'd have to coordinate future extension. If we leave it out as a third-party implementation of the SocketAppender layout then I can just change it as needed.
>> 
>> Joern.
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Scott Deboy <sc...@gmail.com>.
Chainsaw does a similar thing by adding event properties when the  
event is received. It does this regardless of which Receiver received  
the event.


On Sep 18, 2011, at 4:54 AM, Joern Huxhorn <jh...@googlemail.com>  
wrote:

>
> On 17.09.2011, at 23:42, Ralph Goers wrote:
>
>>
>> On Sep 17, 2011, at 1:43 PM, Joern Huxhorn wrote:
>>
>>>
>>> On 17.09.2011, at 21:26, Ralph Goers wrote:
>>>
>>>>
>>>> On Sep 17, 2011, at 11:40 AM, Joern Huxhorn wrote:
>>>>
>>>>>
>>>>> On 17.09.2011, at 18:47, John Vasileff wrote:
>>>>>
>>>>>>
>>>>>> On Sep 17, 2011, at 8:53 AM, Joern Huxhorn wrote:
>>>>>>
>>>>>> Interesting point on serialization.  When would you see  
>>>>>> serialization happening?  Is this primarily for appenders?
>>>>>>
>>>>>
>>>>> SocketAppender is using serialization. Since I'm the author of  
>>>>> Lilith ( http://lilith.huxhorn.de/ ) I tend to focus on stuff  
>>>>> like that.
>>>>
>>>> Actually, in Log4j 2.0 SocketAppender uses a Layout. The default  
>>>> Layout is SerializedLayout. If you want to use a LillithLayout  
>>>> you would be free to do so.
>>>>
>>>>>
>>>>> This is also the reason for the differentiation between the  
>>>>> Message instance and the (laziliy) formatted  message string. A  
>>>>> SocketAppender does not have any need for a formatted message.  
>>>>> It is perfectly valid to skip the formatting entirely and simply  
>>>>> transmit the message pattern and the message parameters (as  
>>>>> Strings) to safe some CPU in the logged application.
>>>>
>>>> I disagree. The SocketAppender should be able to interact with  
>>>> something that accepts Thrift, Avro, Hession or other  
>>>> serialization protocols or even the RFC 5424 format.  However, in  
>>>> cases where the event is serialized into a format where the  
>>>> LogEvent will be recreated on the other side of the socket  
>>>> connection, I agree that formatting the message on the sender's  
>>>> side is not required.
>>>
>>> Your SocketAppender is obviously much improved compared to the  
>>> Logback one. Having the actual serialization mechanism pluggable  
>>> is a very good idea.
>>> Nevertheless, I assume that simple serialization would be the  
>>> "reference implementation". I'd, of course, hook in my protobuf  
>>> implementation...
>>
>> If you provide a ProtobufLayout I'd happily include it - although  
>> I'd make the protobuf artifacts optional dependencies as I did for  
>> Flume.
>
> Well, I could give you my protobuf but I'm not sure if it makes  
> sense to add it to Log4J directly.
>
> It contains more (optional) fields than Log4J will provide,  
> partially since populating those fields has a performance impact.  
> JUL has an event id by Thread but providing them would require  
> ThreadLocal handling of the counter, i.e. reduces performance for  
> very little additional info. Who would really use this information?
> I keep those infos in Lilith so it can import/receive events  
> lossless but I don't think that Log4J should support them.
>
> So it's probably best to keep this out of the Log4J codebase. If we  
> add it then we'd have to coordinate future extension. If we leave it  
> out as a third-party implementation of the SocketAppender layout  
> then I can just change it as needed.
>
> Joern.
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 18, 2011, at 4:54 AM, Joern Huxhorn wrote:

> 
> Well, I could give you my protobuf but I'm not sure if it makes sense to add it to Log4J directly.
> 
> It contains more (optional) fields than Log4J will provide, partially since populating those fields has a performance impact. JUL has an event id by Thread but providing them would require ThreadLocal handling of the counter, i.e. reduces performance for very little additional info. Who would really use this information?
> I keep those infos in Lilith so it can import/receive events lossless but I don't think that Log4J should support them.

Hmmm. I faced something similar in the Flume Appender. You might want to look at the UUIDUtil class. It generates a UUID that should be unique across servers for 8,925 years. 
> 
> So it's probably best to keep this out of the Log4J codebase. If we add it then we'd have to coordinate future extension. If we leave it out as a third-party implementation of the SocketAppender layout then I can just change it as needed.

OK.

Ralph


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Joern Huxhorn <jh...@googlemail.com>.
On 17.09.2011, at 23:42, Ralph Goers wrote:

> 
> On Sep 17, 2011, at 1:43 PM, Joern Huxhorn wrote:
> 
>> 
>> On 17.09.2011, at 21:26, Ralph Goers wrote:
>> 
>>> 
>>> On Sep 17, 2011, at 11:40 AM, Joern Huxhorn wrote:
>>> 
>>>> 
>>>> On 17.09.2011, at 18:47, John Vasileff wrote:
>>>> 
>>>>> 
>>>>> On Sep 17, 2011, at 8:53 AM, Joern Huxhorn wrote:
>>>>> 
>>>>> Interesting point on serialization.  When would you see serialization happening?  Is this primarily for appenders?
>>>>> 
>>>> 
>>>> SocketAppender is using serialization. Since I'm the author of Lilith ( http://lilith.huxhorn.de/ ) I tend to focus on stuff like that.
>>> 
>>> Actually, in Log4j 2.0 SocketAppender uses a Layout. The default Layout is SerializedLayout. If you want to use a LillithLayout you would be free to do so.
>>> 
>>>> 
>>>> This is also the reason for the differentiation between the Message instance and the (laziliy) formatted  message string. A SocketAppender does not have any need for a formatted message. It is perfectly valid to skip the formatting entirely and simply transmit the message pattern and the message parameters (as Strings) to safe some CPU in the logged application.
>>> 
>>> I disagree. The SocketAppender should be able to interact with something that accepts Thrift, Avro, Hession or other serialization protocols or even the RFC 5424 format.  However, in cases where the event is serialized into a format where the LogEvent will be recreated on the other side of the socket connection, I agree that formatting the message on the sender's side is not required.
>> 
>> Your SocketAppender is obviously much improved compared to the Logback one. Having the actual serialization mechanism pluggable is a very good idea.
>> Nevertheless, I assume that simple serialization would be the "reference implementation". I'd, of course, hook in my protobuf implementation...
> 
> If you provide a ProtobufLayout I'd happily include it - although I'd make the protobuf artifacts optional dependencies as I did for Flume.

Well, I could give you my protobuf but I'm not sure if it makes sense to add it to Log4J directly.

It contains more (optional) fields than Log4J will provide, partially since populating those fields has a performance impact. JUL has an event id by Thread but providing them would require ThreadLocal handling of the counter, i.e. reduces performance for very little additional info. Who would really use this information?
I keep those infos in Lilith so it can import/receive events lossless but I don't think that Log4J should support them.

So it's probably best to keep this out of the Log4J codebase. If we add it then we'd have to coordinate future extension. If we leave it out as a third-party implementation of the SocketAppender layout then I can just change it as needed.

Joern.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 17, 2011, at 1:43 PM, Joern Huxhorn wrote:

> 
> On 17.09.2011, at 21:26, Ralph Goers wrote:
> 
>> 
>> On Sep 17, 2011, at 11:40 AM, Joern Huxhorn wrote:
>> 
>>> 
>>> On 17.09.2011, at 18:47, John Vasileff wrote:
>>> 
>>>> 
>>>> On Sep 17, 2011, at 8:53 AM, Joern Huxhorn wrote:
>>>> 
>>>> Interesting point on serialization.  When would you see serialization happening?  Is this primarily for appenders?
>>>> 
>>> 
>>> SocketAppender is using serialization. Since I'm the author of Lilith ( http://lilith.huxhorn.de/ ) I tend to focus on stuff like that.
>> 
>> Actually, in Log4j 2.0 SocketAppender uses a Layout. The default Layout is SerializedLayout. If you want to use a LillithLayout you would be free to do so.
>> 
>>> 
>>> This is also the reason for the differentiation between the Message instance and the (laziliy) formatted  message string. A SocketAppender does not have any need for a formatted message. It is perfectly valid to skip the formatting entirely and simply transmit the message pattern and the message parameters (as Strings) to safe some CPU in the logged application.
>> 
>> I disagree. The SocketAppender should be able to interact with something that accepts Thrift, Avro, Hession or other serialization protocols or even the RFC 5424 format.  However, in cases where the event is serialized into a format where the LogEvent will be recreated on the other side of the socket connection, I agree that formatting the message on the sender's side is not required.
> 
> Your SocketAppender is obviously much improved compared to the Logback one. Having the actual serialization mechanism pluggable is a very good idea.
> Nevertheless, I assume that simple serialization would be the "reference implementation". I'd, of course, hook in my protobuf implementation...

If you provide a ProtobufLayout I'd happily include it - although I'd make the protobuf artifacts optional dependencies as I did for Flume.

Ralph
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Joern Huxhorn <jh...@googlemail.com>.
On 17.09.2011, at 21:26, Ralph Goers wrote:

> 
> On Sep 17, 2011, at 11:40 AM, Joern Huxhorn wrote:
> 
>> 
>> On 17.09.2011, at 18:47, John Vasileff wrote:
>> 
>>> 
>>> On Sep 17, 2011, at 8:53 AM, Joern Huxhorn wrote:
>>> 
>>> Interesting point on serialization.  When would you see serialization happening?  Is this primarily for appenders?
>>> 
>> 
>> SocketAppender is using serialization. Since I'm the author of Lilith ( http://lilith.huxhorn.de/ ) I tend to focus on stuff like that.
> 
> Actually, in Log4j 2.0 SocketAppender uses a Layout. The default Layout is SerializedLayout. If you want to use a LillithLayout you would be free to do so.
> 
>> 
>> This is also the reason for the differentiation between the Message instance and the (laziliy) formatted  message string. A SocketAppender does not have any need for a formatted message. It is perfectly valid to skip the formatting entirely and simply transmit the message pattern and the message parameters (as Strings) to safe some CPU in the logged application.
> 
> I disagree. The SocketAppender should be able to interact with something that accepts Thrift, Avro, Hession or other serialization protocols or even the RFC 5424 format.  However, in cases where the event is serialized into a format where the LogEvent will be recreated on the other side of the socket connection, I agree that formatting the message on the sender's side is not required.

Your SocketAppender is obviously much improved compared to the Logback one. Having the actual serialization mechanism pluggable is a very good idea.
Nevertheless, I assume that simple serialization would be the "reference implementation". I'd, of course, hook in my protobuf implementation...

Joern.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 17, 2011, at 11:40 AM, Joern Huxhorn wrote:

> 
> On 17.09.2011, at 18:47, John Vasileff wrote:
> 
>> 
>> On Sep 17, 2011, at 8:53 AM, Joern Huxhorn wrote:
>> 
>>> Adding getThrowable() would also reintroduce the issue that such a Message could not be serialized securely since deserialization would require the exceptions class on the classpath. In my ParameterizedMessage over at https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/n/messages/ParameterizedMessage.java the Throwable is transient so it is deliberately lost while serializing, i.e. it must be taken care of by the framework immediately after the message is created.
>>> 
>>> It is only contained in ParameterizedMessage at all simply because a method can only return a single value. And the create-method is also responsible for resolving the Throwable at the last position of arguments if it is not used up by a corresponding {}.
>>> 
>>> Yes, it would be "cleaner" to split that into a parseresult object that contains both the message and an additional, optional Throwable. I just didn't implement it that way to reduce the amount of garbage (that parseresult object would get garbage-collected immediately after evaluation).
>>> 
>>> So adding Throwable to ParameterizedMessage was just a performance optimization.
>>> 
>>> The serialization issue is btw also the reason for *not* having Object[] getParameters() but String[] getParameters() instead. The String representation is the serialization-safe version of the parameters.
>>> 
>>> But all of this is, in my books, an implementation detail of the Message implementation with getFormattedMessage() being the only "public" API of Message.
>>> 
>>> Joern.
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>>> 
>> 
>> Interesting point on serialization.  When would you see serialization happening?  Is this primarily for appenders?
>> 
> 
> SocketAppender is using serialization. Since I'm the author of Lilith ( http://lilith.huxhorn.de/ ) I tend to focus on stuff like that.

Actually, in Log4j 2.0 SocketAppender uses a Layout. The default Layout is SerializedLayout. If you want to use a LillithLayout you would be free to do so.

> 
> This is also the reason for the differentiation between the Message instance and the (laziliy) formatted  message string. A SocketAppender does not have any need for a formatted message. It is perfectly valid to skip the formatting entirely and simply transmit the message pattern and the message parameters (as Strings) to safe some CPU in the logged application.

I disagree. The SocketAppender should be able to interact with something that accepts Thrift, Avro, Hession or other serialization protocols or even the RFC 5424 format.  However, in cases where the event is serialized into a format where the LogEvent will be recreated on the other side of the socket connection, I agree that formatting the message on the sender's side is not required.

> 
> Directly converting parameters into Strings as soon as we know that an event really needs to be created is crucial to make sure that the logging framework is not lying as is happening, for example, in this case: http://techblog.appnexus.com/2011/webkit-chrome-safari-console-log-bug/
> A lying logging framework is really, really bad...

Agreed.

Ralph
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Joern Huxhorn <jh...@googlemail.com>.
On 17.09.2011, at 18:47, John Vasileff wrote:

> 
> On Sep 17, 2011, at 8:53 AM, Joern Huxhorn wrote:
> 
>> Adding getThrowable() would also reintroduce the issue that such a Message could not be serialized securely since deserialization would require the exceptions class on the classpath. In my ParameterizedMessage over at https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/n/messages/ParameterizedMessage.java the Throwable is transient so it is deliberately lost while serializing, i.e. it must be taken care of by the framework immediately after the message is created.
>> 
>> It is only contained in ParameterizedMessage at all simply because a method can only return a single value. And the create-method is also responsible for resolving the Throwable at the last position of arguments if it is not used up by a corresponding {}.
>> 
>> Yes, it would be "cleaner" to split that into a parseresult object that contains both the message and an additional, optional Throwable. I just didn't implement it that way to reduce the amount of garbage (that parseresult object would get garbage-collected immediately after evaluation).
>> 
>> So adding Throwable to ParameterizedMessage was just a performance optimization.
>> 
>> The serialization issue is btw also the reason for *not* having Object[] getParameters() but String[] getParameters() instead. The String representation is the serialization-safe version of the parameters.
>> 
>> But all of this is, in my books, an implementation detail of the Message implementation with getFormattedMessage() being the only "public" API of Message.
>> 
>> Joern.
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>> 
> 
> Interesting point on serialization.  When would you see serialization happening?  Is this primarily for appenders?
> 

SocketAppender is using serialization. Since I'm the author of Lilith ( http://lilith.huxhorn.de/ ) I tend to focus on stuff like that.

This is also the reason for the differentiation between the Message instance and the (laziliy) formatted  message string. A SocketAppender does not have any need for a formatted message. It is perfectly valid to skip the formatting entirely and simply transmit the message pattern and the message parameters (as Strings) to safe some CPU in the logged application.

Directly converting parameters into Strings as soon as we know that an event really needs to be created is crucial to make sure that the logging framework is not lying as is happening, for example, in this case: http://techblog.appnexus.com/2011/webkit-chrome-safari-console-log-bug/
A lying logging framework is really, really bad...

Joern.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by John Vasileff <jo...@gmail.com>.
On Sep 17, 2011, at 8:53 AM, Joern Huxhorn wrote:

> Adding getThrowable() would also reintroduce the issue that such a Message could not be serialized securely since deserialization would require the exceptions class on the classpath. In my ParameterizedMessage over at https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/n/messages/ParameterizedMessage.java the Throwable is transient so it is deliberately lost while serializing, i.e. it must be taken care of by the framework immediately after the message is created.
> 
> It is only contained in ParameterizedMessage at all simply because a method can only return a single value. And the create-method is also responsible for resolving the Throwable at the last position of arguments if it is not used up by a corresponding {}.
> 
> Yes, it would be "cleaner" to split that into a parseresult object that contains both the message and an additional, optional Throwable. I just didn't implement it that way to reduce the amount of garbage (that parseresult object would get garbage-collected immediately after evaluation).
> 
> So adding Throwable to ParameterizedMessage was just a performance optimization.
> 
> The serialization issue is btw also the reason for *not* having Object[] getParameters() but String[] getParameters() instead. The String representation is the serialization-safe version of the parameters.
> 
> But all of this is, in my books, an implementation detail of the Message implementation with getFormattedMessage() being the only "public" API of Message.
> 
> Joern.
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
> 

Interesting point on serialization.  When would you see serialization happening?  Is this primarily for appenders?


John
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Joern Huxhorn <jh...@googlemail.com>.
On 17.09.2011, at 05:19, Ralph Goers wrote:

> 
> On Sep 16, 2011, at 5:09 PM, John Vasileff wrote:
> 
>> 
>> On Sep 16, 2011, at 7:41 PM, Joern Huxhorn wrote:
>> 
>>> 
>>> On 16.09.2011, at 19:09, John Vasileff wrote:
>>> 
>>>> 
>>>> On Sep 15, 2011, at 7:46 PM, Ralph Goers wrote:
>>>> 
>>>>> My gut reaction is that I agree with you. I ran across this behavior a while ago and Joern mentioned that ParameterizedMessage was working the way it is supposed to, which given the behavior you are noting just doesn't seem correct.
>>>>> 
>>>>> On the other hand, currently not every Message implementation cares about Throwables.  I'm not sure what StructuredDataMessage should do with one, for example.  What do you think should be done to handle that?
>>>>> 
>>>> 
>>>> I think it is analogous to getParameters().  It is a common feature, but not one that all Message types need.  So I think the question is how granular the interfaces should be.  Message could have _only_ getFormattedMessage(), and everything else added by sub interfaces.  But for very common things like Throwables or Parameters, I tend to think it is easier to have them in the main Message interface and avoid instanceof clutter in the rest of the code.
>>>> 
>>> 
>>> I wonder why you are so keen to extend the basic Message interface with arbitrary methods that are only relevant for certain Message implementations?
>>> 
>>> The Runnable interface does also only have a run() method and not some obscure Object[] getArguments() / void setArguments(Object[]) methods.
>>> 
>> 
>> It is not so much that I think the Message interface should have getThrowable().  It is that I think that message objects should carry the throwable, if one exists.
>> 
>> void info(Message msg);
>> void info(Message msg, Throwable t);
>> 
>> I don't think the second method above should exist, just as we don't have:
>> 
>> void info(Message msg, Object[] params);
>> 
>> I would be happy to rework the patch with something like:
>> 
>> interface Message { public String getFormattedMessage(); }
>> interface ThrowableMessage { public Throwable getThrowable(); }
>> interface ParameterizedMessage { public Object[] getParameters(); }
>> etc.
>> 
>> We would need to think through the appropriate granularity and try to figure out what the best mix of interfaces is.
> 
> With the above we would still need to support
> 
> void info(Message msg, Throwable t)
> 
> even though the Message interface might be one that implements ThrowableMessage to allow support for those that don't.  That would be a bit awkward wouldn't it? That also means filters and appenders would need to check to see if Message implements ThrowableMessage and then look in the LogEvent for the Throwable if it doesn't.
> 

Adding getThrowable() would also reintroduce the issue that such a Message could not be serialized securely since deserialization would require the exceptions class on the classpath. In my ParameterizedMessage over at https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/n/messages/ParameterizedMessage.java the Throwable is transient so it is deliberately lost while serializing, i.e. it must be taken care of by the framework immediately after the message is created.

It is only contained in ParameterizedMessage at all simply because a method can only return a single value. And the create-method is also responsible for resolving the Throwable at the last position of arguments if it is not used up by a corresponding {}.

Yes, it would be "cleaner" to split that into a parseresult object that contains both the message and an additional, optional Throwable. I just didn't implement it that way to reduce the amount of garbage (that parseresult object would get garbage-collected immediately after evaluation).

So adding Throwable to ParameterizedMessage was just a performance optimization.

The serialization issue is btw also the reason for *not* having Object[] getParameters() but String[] getParameters() instead. The String representation is the serialization-safe version of the parameters.

But all of this is, in my books, an implementation detail of the Message implementation with getFormattedMessage() being the only "public" API of Message.

Joern.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 16, 2011, at 5:09 PM, John Vasileff wrote:

> 
> On Sep 16, 2011, at 7:41 PM, Joern Huxhorn wrote:
> 
>> 
>> On 16.09.2011, at 19:09, John Vasileff wrote:
>> 
>>> 
>>> On Sep 15, 2011, at 7:46 PM, Ralph Goers wrote:
>>> 
>>>> My gut reaction is that I agree with you. I ran across this behavior a while ago and Joern mentioned that ParameterizedMessage was working the way it is supposed to, which given the behavior you are noting just doesn't seem correct.
>>>> 
>>>> On the other hand, currently not every Message implementation cares about Throwables.  I'm not sure what StructuredDataMessage should do with one, for example.  What do you think should be done to handle that?
>>>> 
>>> 
>>> I think it is analogous to getParameters().  It is a common feature, but not one that all Message types need.  So I think the question is how granular the interfaces should be.  Message could have _only_ getFormattedMessage(), and everything else added by sub interfaces.  But for very common things like Throwables or Parameters, I tend to think it is easier to have them in the main Message interface and avoid instanceof clutter in the rest of the code.
>>> 
>> 
>> I wonder why you are so keen to extend the basic Message interface with arbitrary methods that are only relevant for certain Message implementations?
>> 
>> The Runnable interface does also only have a run() method and not some obscure Object[] getArguments() / void setArguments(Object[]) methods.
>> 
> 
> It is not so much that I think the Message interface should have getThrowable().  It is that I think that message objects should carry the throwable, if one exists.
> 
> void info(Message msg);
> void info(Message msg, Throwable t);
> 
> I don't think the second method above should exist, just as we don't have:
> 
> void info(Message msg, Object[] params);
> 
> I would be happy to rework the patch with something like:
> 
> interface Message { public String getFormattedMessage(); }
> interface ThrowableMessage { public Throwable getThrowable(); }
> interface ParameterizedMessage { public Object[] getParameters(); }
> etc.
> 
> We would need to think through the appropriate granularity and try to figure out what the best mix of interfaces is.

With the above we would still need to support

void info(Message msg, Throwable t)

even though the Message interface might be one that implements ThrowableMessage to allow support for those that don't.  That would be a bit awkward wouldn't it? That also means filters and appenders would need to check to see if Message implements ThrowableMessage and then look in the LogEvent for the Throwable if it doesn't.


Ralph



---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by John Vasileff <jo...@gmail.com>.
On Sep 16, 2011, at 7:41 PM, Joern Huxhorn wrote:

> 
> On 16.09.2011, at 19:09, John Vasileff wrote:
> 
>> 
>> On Sep 15, 2011, at 7:46 PM, Ralph Goers wrote:
>> 
>>> My gut reaction is that I agree with you. I ran across this behavior a while ago and Joern mentioned that ParameterizedMessage was working the way it is supposed to, which given the behavior you are noting just doesn't seem correct.
>>> 
>>> On the other hand, currently not every Message implementation cares about Throwables.  I'm not sure what StructuredDataMessage should do with one, for example.  What do you think should be done to handle that?
>>> 
>> 
>> I think it is analogous to getParameters().  It is a common feature, but not one that all Message types need.  So I think the question is how granular the interfaces should be.  Message could have _only_ getFormattedMessage(), and everything else added by sub interfaces.  But for very common things like Throwables or Parameters, I tend to think it is easier to have them in the main Message interface and avoid instanceof clutter in the rest of the code.
>> 
> 
> I wonder why you are so keen to extend the basic Message interface with arbitrary methods that are only relevant for certain Message implementations?
> 
> The Runnable interface does also only have a run() method and not some obscure Object[] getArguments() / void setArguments(Object[]) methods.
> 

It is not so much that I think the Message interface should have getThrowable().  It is that I think that message objects should carry the throwable, if one exists.

void info(Message msg);
void info(Message msg, Throwable t);

I don't think the second method above should exist, just as we don't have:

void info(Message msg, Object[] params);

I would be happy to rework the patch with something like:

interface Message { public String getFormattedMessage(); }
interface ThrowableMessage { public Throwable getThrowable(); }
interface ParameterizedMessage { public Object[] getParameters(); }
etc.

We would need to think through the appropriate granularity and try to figure out what the best mix of interfaces is.

I agree keeping getThrowable() out of Message would be more pure from a design standpoint.  The reason I lean towards adding it is that since it is so common, it avoids several instanceof checks.  A bit of a compromise for convenience sake.  (Not that instanceof is great from a design standpoint either, but it is inherent in concept of having Messages.)

> 
>> SimpleMessage has:
>> 
>>   /**
>>    * Returns null since there are no parameters.
>>    * @return null.
>>    */
>>   public Object[] getParameters() {
>>       return null;
>>   }
>> 
>> So StructuredDataMessage can have:
>> 
>>   /**
>>    * @return null; StrucutredDataMessages never have Throwables.
>>    */
>>   public Throwable getThrowable() {
>>       return null;
>>   }
>> 
> 
> But what about tracing messages? Those could have a TraceMessageType (ENTERING, EXITING, THROWING).
> Shouldn't we add that to the Message interface, too, and just return null in case of every other Message implementation?
> 
> Sorry about my sarcasm (and yes, that's only sarcasm. I'm not suggesting to add this to the Message interface ;)) but I just don't see the reason and rationale for those methods.
> 
> Joern
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Joern Huxhorn <jh...@googlemail.com>.
On 16.09.2011, at 19:09, John Vasileff wrote:

> 
> On Sep 15, 2011, at 7:46 PM, Ralph Goers wrote:
> 
>> My gut reaction is that I agree with you. I ran across this behavior a while ago and Joern mentioned that ParameterizedMessage was working the way it is supposed to, which given the behavior you are noting just doesn't seem correct.
>> 
>> On the other hand, currently not every Message implementation cares about Throwables.  I'm not sure what StructuredDataMessage should do with one, for example.  What do you think should be done to handle that?
>> 
> 
> I think it is analogous to getParameters().  It is a common feature, but not one that all Message types need.  So I think the question is how granular the interfaces should be.  Message could have _only_ getFormattedMessage(), and everything else added by sub interfaces.  But for very common things like Throwables or Parameters, I tend to think it is easier to have them in the main Message interface and avoid instanceof clutter in the rest of the code.
> 

I wonder why you are so keen to extend the basic Message interface with arbitrary methods that are only relevant for certain Message implementations?

The Runnable interface does also only have a run() method and not some obscure Object[] getArguments() / void setArguments(Object[]) methods.


> SimpleMessage has:
> 
>    /**
>     * Returns null since there are no parameters.
>     * @return null.
>     */
>    public Object[] getParameters() {
>        return null;
>    }
> 
> So StructuredDataMessage can have:
> 
>    /**
>     * @return null; StrucutredDataMessages never have Throwables.
>     */
>    public Throwable getThrowable() {
>        return null;
>    }
> 

But what about tracing messages? Those could have a TraceMessageType (ENTERING, EXITING, THROWING).
Shouldn't we add that to the Message interface, too, and just return null in case of every other Message implementation?

Sorry about my sarcasm (and yes, that's only sarcasm. I'm not suggesting to add this to the Message interface ;)) but I just don't see the reason and rationale for those methods.

Joern
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
On Sep 16, 2011, at 10:32 AM, Scott Deboy wrote:

> Does it help to provide the Throwable as the first argument?  That's what some of the overloaded LogSF/MF methods do to avoid ambiguity, if I recall.

Putting the Throwable before the argument array does help.  Unfortunately it also makes bridging an API such as the one below from SLF4J a bit harder.

    public void error(Marker marker, String s, Object[] objects) {
        if (isErrorEnabled(marker)) {
            log((org.apache.logging.log4j.Marker) marker, FQCN, Level.ERROR,
                new ParameterizedMessage(s, objects), null);
        }
    }

Since SLF4J doesn't include an explicit Throwable we would need to do

    public void error(Marker marker, String s, Object[] objects) {
        if (isErrorEnabled(marker)) {
            Object[] arrary;
            Throwable t = null;
            if (objects == null || objects.length == 0) {
                array = objects;
            } else if (objects[objects.length - 1] instanceof Throwable) {
                t = objects[objects.length - 1];
               array = new Object[object.length -1];
               System.arraycopy(objects, 0, array, 0, objects.length - 1);
            }
            log((org.apache.logging.log4j.Marker) marker, FQCN, Level.ERROR,
                new ParameterizedMessage(s, array), t);
        }
    }

Currently parameterized message determines whether the last argument is a Throwable.  As John has pointed out though, it is being ignored when the LogEvent is created and by Layouts, etc.

Ralph
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Scott Deboy <sc...@gmail.com>.
Does it help to provide the Throwable as the first argument?  That's what
some of the overloaded LogSF/MF methods do to avoid ambiguity, if I recall.

On Fri, Sep 16, 2011 at 10:09 AM, John Vasileff <jo...@gmail.com>wrote:

>
> On Sep 15, 2011, at 7:46 PM, Ralph Goers wrote:
>
> > My gut reaction is that I agree with you. I ran across this behavior a
> while ago and Joern mentioned that ParameterizedMessage was working the way
> it is supposed to, which given the behavior you are noting just doesn't seem
> correct.
> >
> > On the other hand, currently not every Message implementation cares about
> Throwables.  I'm not sure what StructuredDataMessage should do with one, for
> example.  What do you think should be done to handle that?
> >
>
> I think it is analogous to getParameters().  It is a common feature, but
> not one that all Message types need.  So I think the question is how
> granular the interfaces should be.  Message could have _only_
> getFormattedMessage(), and everything else added by sub interfaces.  But for
> very common things like Throwables or Parameters, I tend to think it is
> easier to have them in the main Message interface and avoid instanceof
> clutter in the rest of the code.
>
> SimpleMessage has:
>
>    /**
>     * Returns null since there are no parameters.
>     * @return null.
>     */
>    public Object[] getParameters() {
>        return null;
>    }
>
> So StructuredDataMessage can have:
>
>    /**
>     * @return null; StrucutredDataMessages never have Throwables.
>     */
>    public Throwable getThrowable() {
>        return null;
>     }
>
>
> > I realized the other day in an email exchange with Joern that I had
> neglected to support the ExtendedThrowablePatternConverter and have been
> working on that.  Once I complete that I'll be happy to work on this. If you
> have ideas feel free to submit Jira patches. If you don't have an ICLA on
> file I would suggest you do that.  I would love to have your help in taking
> this forward.
> >
>
> A patch for this is on the way.
>
> > Ralph
> >
> > On Sep 15, 2011, at 9:32 AM, John Vasileff wrote:
> >
> >> Should logs that use ParameterizedMessage support trailing throwables?
> The ParameterizedMessage code identifies throwables in the argument array,
> but they are silently ignored.  This is for methods like:
> >>
> >> void info(String message, Object... params);
> >>
> >> Example:
> >>
> >> log4j2Logger.info("log4j2Logger no params with throwable?", t); // works
> >> log4j2Logger.info("log4j2Logger {}", "params with throwable?", t); //
> fails
> >>
> >> Output:
> >>
> >> 2011-09-15 11:55:40,497 INFO Log4j2Testing [main] log4j2Logger no params
> with throwable?
> >> java.lang.Throwable
> >>      at Log4j2Testing.main(Log4j2Testing.java:18)
> >> 2011-09-15 11:55:40,499 INFO Log4j2Testing [main] log4j2Logger params
> with throwable?
> >>
> >>
> >> On a related note, consider Logger methods like the following:
> >>
> >> void info(Message msg);
> >> void info(Message msg, Throwable t);
> >>
> >> If Message objects support Throwables, as may be true for
> ParameterizedMessage or future message types (end user created or new to be
> conceived log4j2 standard messages), there is ambiguity in the second method
> as to which throwable is "the" throwable.  Perhaps the first non-null, or
> maybe the explicit argument overrides the msg throwable.  In any case, it is
> a bit confusing.
> >>
> >> Perhaps the second method with an explicit Throwable should be
> eliminated, and Message objects should support Throwables when desired.
>  getThrowable() could be added to the Message interface, or even a separate
> MessageWithThrowable interface similar to the way FormattedMessage works.
>  (The former may be better to avoid having too many interfaces and
> instanceof clutter.)
> >>
> >> It seems to me that throwables are a natural part of messages, just as
> the formatted message strings and parameters are.
> >>
> >> It doesn't look like adding throwables to Messages would cause
> additional overhead.  In cases like ParameterizedMessage, it standardizes
> the approach to throwables and gives the Message object more power.  In
> other cases, it just changes the location of a parenthesis in the code:
> >>
> >> public void info(String message, Throwable t) {
> >>   if (isEnabled(Level.INFO, null, message, t)) {
> >>       log(null, getFQCN(), Level.INFO, new SimpleMessage(message), t);
> >>   }
> >> }
> >>
> >> becomes:
> >> ...
> >>       log(null, getFQCN(), Level.INFO, new SimpleMessage(message, t));
> >> ...
> >>
> >>
> >>
> >> John
> >> ---------------------------------------------------------------------
> >> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> >> For additional commands, e-mail: log4j-dev-help@logging.apache.org
> >>
> >
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> > For additional commands, e-mail: log4j-dev-help@logging.apache.org
> >
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>
>

Re: log4j2 parameterized msg with throwable

Posted by John Vasileff <jo...@gmail.com>.
On Sep 15, 2011, at 7:46 PM, Ralph Goers wrote:

> My gut reaction is that I agree with you. I ran across this behavior a while ago and Joern mentioned that ParameterizedMessage was working the way it is supposed to, which given the behavior you are noting just doesn't seem correct.
> 
> On the other hand, currently not every Message implementation cares about Throwables.  I'm not sure what StructuredDataMessage should do with one, for example.  What do you think should be done to handle that?
> 

I think it is analogous to getParameters().  It is a common feature, but not one that all Message types need.  So I think the question is how granular the interfaces should be.  Message could have _only_ getFormattedMessage(), and everything else added by sub interfaces.  But for very common things like Throwables or Parameters, I tend to think it is easier to have them in the main Message interface and avoid instanceof clutter in the rest of the code.

SimpleMessage has:

    /**
     * Returns null since there are no parameters.
     * @return null.
     */
    public Object[] getParameters() {
        return null;
    }

So StructuredDataMessage can have:

    /**
     * @return null; StrucutredDataMessages never have Throwables.
     */
    public Throwable getThrowable() {
        return null;
    }


> I realized the other day in an email exchange with Joern that I had neglected to support the ExtendedThrowablePatternConverter and have been working on that.  Once I complete that I'll be happy to work on this. If you have ideas feel free to submit Jira patches. If you don't have an ICLA on file I would suggest you do that.  I would love to have your help in taking this forward.
> 

A patch for this is on the way.

> Ralph
> 
> On Sep 15, 2011, at 9:32 AM, John Vasileff wrote:
> 
>> Should logs that use ParameterizedMessage support trailing throwables? The ParameterizedMessage code identifies throwables in the argument array, but they are silently ignored.  This is for methods like:
>> 
>> void info(String message, Object... params);
>> 
>> Example:
>> 
>> log4j2Logger.info("log4j2Logger no params with throwable?", t); // works
>> log4j2Logger.info("log4j2Logger {}", "params with throwable?", t); // fails
>> 
>> Output:
>> 
>> 2011-09-15 11:55:40,497 INFO Log4j2Testing [main] log4j2Logger no params with throwable?
>> java.lang.Throwable
>> 	at Log4j2Testing.main(Log4j2Testing.java:18)
>> 2011-09-15 11:55:40,499 INFO Log4j2Testing [main] log4j2Logger params with throwable?
>> 
>> 
>> On a related note, consider Logger methods like the following:
>> 
>> void info(Message msg);
>> void info(Message msg, Throwable t);
>> 
>> If Message objects support Throwables, as may be true for ParameterizedMessage or future message types (end user created or new to be conceived log4j2 standard messages), there is ambiguity in the second method as to which throwable is "the" throwable.  Perhaps the first non-null, or maybe the explicit argument overrides the msg throwable.  In any case, it is a bit confusing.
>> 
>> Perhaps the second method with an explicit Throwable should be eliminated, and Message objects should support Throwables when desired.  getThrowable() could be added to the Message interface, or even a separate MessageWithThrowable interface similar to the way FormattedMessage works.  (The former may be better to avoid having too many interfaces and instanceof clutter.)
>> 
>> It seems to me that throwables are a natural part of messages, just as the formatted message strings and parameters are.
>> 
>> It doesn't look like adding throwables to Messages would cause additional overhead.  In cases like ParameterizedMessage, it standardizes the approach to throwables and gives the Message object more power.  In other cases, it just changes the location of a parenthesis in the code:
>> 
>> public void info(String message, Throwable t) {
>>   if (isEnabled(Level.INFO, null, message, t)) {
>>       log(null, getFQCN(), Level.INFO, new SimpleMessage(message), t);
>>   }
>> }
>> 
>> becomes:
>> ...
>>       log(null, getFQCN(), Level.INFO, new SimpleMessage(message, t));
>> ...
>> 
>> 
>> 
>> John
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>> 
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Re: log4j2 parameterized msg with throwable

Posted by Ralph Goers <ra...@dslextreme.com>.
My gut reaction is that I agree with you. I ran across this behavior a while ago and Joern mentioned that ParameterizedMessage was working the way it is supposed to, which given the behavior you are noting just doesn't seem correct.

On the other hand, currently not every Message implementation cares about Throwables.  I'm not sure what StructuredDataMessage should do with one, for example.  What do you think should be done to handle that?

I realized the other day in an email exchange with Joern that I had neglected to support the ExtendedThrowablePatternConverter and have been working on that.  Once I complete that I'll be happy to work on this. If you have ideas feel free to submit Jira patches. If you don't have an ICLA on file I would suggest you do that.  I would love to have your help in taking this forward.

Ralph

On Sep 15, 2011, at 9:32 AM, John Vasileff wrote:

> Should logs that use ParameterizedMessage support trailing throwables? The ParameterizedMessage code identifies throwables in the argument array, but they are silently ignored.  This is for methods like:
> 
> void info(String message, Object... params);
> 
> Example:
> 
> log4j2Logger.info("log4j2Logger no params with throwable?", t); // works
> log4j2Logger.info("log4j2Logger {}", "params with throwable?", t); // fails
> 
> Output:
> 
> 2011-09-15 11:55:40,497 INFO Log4j2Testing [main] log4j2Logger no params with throwable?
> java.lang.Throwable
> 	at Log4j2Testing.main(Log4j2Testing.java:18)
> 2011-09-15 11:55:40,499 INFO Log4j2Testing [main] log4j2Logger params with throwable?
> 
> 
> On a related note, consider Logger methods like the following:
> 
> void info(Message msg);
> void info(Message msg, Throwable t);
> 
> If Message objects support Throwables, as may be true for ParameterizedMessage or future message types (end user created or new to be conceived log4j2 standard messages), there is ambiguity in the second method as to which throwable is "the" throwable.  Perhaps the first non-null, or maybe the explicit argument overrides the msg throwable.  In any case, it is a bit confusing.
> 
> Perhaps the second method with an explicit Throwable should be eliminated, and Message objects should support Throwables when desired.  getThrowable() could be added to the Message interface, or even a separate MessageWithThrowable interface similar to the way FormattedMessage works.  (The former may be better to avoid having too many interfaces and instanceof clutter.)
> 
> It seems to me that throwables are a natural part of messages, just as the formatted message strings and parameters are.
> 
> It doesn't look like adding throwables to Messages would cause additional overhead.  In cases like ParameterizedMessage, it standardizes the approach to throwables and gives the Message object more power.  In other cases, it just changes the location of a parenthesis in the code:
> 
> public void info(String message, Throwable t) {
>    if (isEnabled(Level.INFO, null, message, t)) {
>        log(null, getFQCN(), Level.INFO, new SimpleMessage(message), t);
>    }
> }
> 
> becomes:
> ...
>        log(null, getFQCN(), Level.INFO, new SimpleMessage(message, t));
> ...
> 
> 
> 
> John
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org