[logback-user] Custom formatting of parameterized string

[Ceki Gulcu]

Hello David,

To avoid reformatting the message multiple times for the same ILoggingEvent, you 
could use an LRUCahce of very small size, say 5. See LRUCache in 
ch.qos.logback.classic.pattern package. If MyMessageConverter had an LRUCache it 
could short circuit secondary calls to  MessageFormat.

Does LRUCache meet your requirements?

David Zeigler wrote:
> 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

-- 
Ceki Gülcü
Logback: The reliable, generic, fast and flexible logging framework for Java.
http://logback.qos.ch