[logback-user] Custom formatting of parameterized string

[David Zeigler]

On Thu, Sep 10, 2009 at 3:30 AM, Ralph Goers<rgoers at apache.org> wrote:
> On Sep 9, 2009, at 7:04 PM, david_z wrote:
>> I appreciate the performance reasons for logback using {} replacement, but
>> it seems like it should be possible to allow the user to provide an
>> alternate formatting strategy if they so desire without negatively
>> impacting
>> the default's performance.  Creating my own MessageConverter, as suggested
>> above, to perform this formatting works fine, except the conversion is
>> performed once per appender per event rather than just once per event.
>>
>> Is there a better way to handle this custom formatting goal?
>
> Actually, the MessageConverter doesn't do anything. All it does is retrieve
> the message as it was formatted by SLF4J. If you want to do formatting then
> create your own layout and/or converter.

Sorry, I was unclear.  What I meant was I tried writing my own converter:

import java.text.MessageFormat;
public class MyMessageConverter extends ClassicConverter {
	@Override
	public String convert(ILoggingEvent event) {
		return MessageFormat.format(event.getMessage(), event.getArgumentArray());
	}
}

>> If not, I have a suggestion for an enhancement.
>> 1. Add a Formatter interface with the method
>>  String format(String messagePattern, Object[] argArray)
>
> Converters implement String convert(ILoggingEvent event).  If you look at
> how the pattern layout works, the parameters for the individual converters
> are passed to them.
>
>> 2. The LoggingEvent would need access to the formatter.  Ideally the
>> Formatter could be configured via the config file as the Converters can
>> be.
>> I don't know enough about the source to flesh this part out well.
>
> It works the other way around. The Converters have access to the logging
> event.
>
>> 3. Modify getFormattedMessage() in the ILoggingEvent implementations
>>  public String getFormattedMessage() {
>>   if (formattedMessage != null) {
>>     return formattedMessage;
>>   }
>>   if (argumentArray != null) {
>>     if (formatter == null) {
>>       formattedMessage = MessageFormatter.arrayFormat(message,
>> argumentArray);
>>     } else {
>>       formattedMessage = formatter.format(message, argumentArray);
>>     }
>>   } else {
>>     formattedMessage = message;
>>   }
>>   return formattedMessage;
>>  }
>> What do you think?
>>
>
> 1. I think Logback already provides a mechanism to do what you want.

The issue I had using my custom converter was that when I had multiple
appenders using different pattern layouts incorporating my converter,
then the conversion code was executed multiple times.  Here's part of
the XML config file to help explain that.
...
	<conversionRule conversionWord="myMessage"
converterClass="logging.MyMessageConverter" />
	<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
		<layout class="ch.qos.logback.classic.PatternLayout">
			<Pattern>%-4relative [%thread] %myMessage%n</Pattern>
		</layout>
	</appender>
	<appender name="STDOUT2" class="ch.qos.logback.core.ConsoleAppender">
		<layout class="ch.qos.logback.classic.PatternLayout">
			<Pattern>%-4relative %myMessage%n</Pattern>
		</layout>
	</appender>
...

A single log.debug() call results in MyMessageConverter.convert()
being called twice.  Ideally, the log message formatting could be
performed once, then the result reused.  This is how LoggingEvent
behaves with is use of org.slf4j.helpers.MessageFormatter (the {}
default formatter).  LoggingEvent formats the message the first time
getFormattedMessage is called, then returns the already formatted
message for subsequent calls.  What I'm proposing, is allowing the
user to create a custom formatter to use instead of LoggingEvent's
default org.slf4j.helpers.MessageFormatter.  You may be right that I
can accomplish the same goal with converters, but I just couldn't find
a way around the multiple executions per log call.

> 2. I've been working on an enhancement to SLF4J and  logback to support RFC
> 5424, the new IETF syslog specification. (See
>  http://tools.ietf.org/html/rfc5424). In particular, the concept of
> Structured Data. You can play with what I have so far by checking it out
> from git://github.com/rgoers/slf4j.git and
> git://github.com/rgoers/logback.git. However, your idea of associating a
> converter with specific keys isn't something I had thought of but is worth
> considering, however I'd probably want to provide the definitions in the
> configuration, not in the actual logger calls. So far I've just focused on

I might be misunderstanding you, but just to be clear, that keyed
format from my previous example wasn't something I came up with.  It's
a standard part of the JDK in java.text.MessageFormat
http://java.sun.com/javase/6/docs/api/java/text/MessageFormat.html.

> implementing something that adheres to the specification but I'd be
> interested in suggestions on how to improve it.
>
Cool, I'll take a look at your branches tomorrow.

>
> Ralph
>
> Ralph

Thanks for the quick reply,
David