Re: [logback-user] Custom formatting of parameterized string
RossJ wrote:
Hello,
I would like to be able to use parameterized logging with a byte[] argument (formatted as a hex string). Obviously this doesn't work today because arrays don't have a toString() implementation.
One way I can see to do this is to modify (or substitute) the ch.qos.logback.classic.pattern.MessageConverter class and base my implementation on the org.slf4j.helpers.MessageFormatter class. I can either build my own logback.jar or manipulate the classpath to make it active.
Is there a better way to do this? Is customization of the parameterized formatting an area that is likely to be enhanced in future releases? Or is my requirement somehow unusual...
/Thanks, Ross.
Hi, I'm new to logback and am in the process of evaluating as a replacement for log4j. A question was raised today at work regarding parameterized logging and the ability to modify logback to support java.text.MessageFormat style formatting in order to, for example, perform date or currency formatting: log.debug("myDate={0,date,MMM d}", myDate); log.debug("myAmount={0,number,currency}", myAmount); or to defer array formatting, similar to the question I'm replying to above. 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? If not, I have a suggestion for an enhancement. 1. Add a Formatter interface with the method String format(String messagePattern, Object[] argArray) 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. 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? Thanks, David -- View this message in context: http://www.nabble.com/Custom-formatting-of-parameterized-string-tp13972167p2... Sent from the Logback User mailing list archive at Nabble.com.
Ceki usually is pretty responsive but I haven't seen him post for a few days. I'm guessing he must be taking a few days off. On Sep 9, 2009, at 7:04 PM, david_z wrote:
Hi, I'm new to logback and am in the process of evaluating as a replacement for log4j. A question was raised today at work regarding parameterized logging and the ability to modify logback to support java.text.MessageFormat style formatting in order to, for example, perform date or currency formatting: log.debug("myDate={0,date,MMM d}", myDate); log.debug("myAmount={0,number,currency}", myAmount);
or to defer array formatting, similar to the question I'm replying to above.
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.
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. 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 implementing something that adheres to the specification but I'd be interested in suggestions on how to improve it. Ralph Ralph
On Thu, Sep 10, 2009 at 3:30 AM, Ralph Goers<rgoers@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
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@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
Ceki, That does help avoid formatting it multiple times. Thanks for the help. In case anyone else wants more information, here is what my test converter looks like now. private static LRUCache<ILoggingEvent, String> cache = new LRUCache<ILoggingEvent, String>(5); public String convert(ILoggingEvent event) { String converted = cache.get(event); if (converted == null) { try { converted = MessageFormat.format(event.getMessage(), event.getArgumentArray()); } catch (IllegalArgumentException e) { converted = "IllegalArgumentException occurred while formatting " + event.getMessage(); } cache.put(event, converted); } return converted; } David On Sun, Sep 13, 2009 at 1:12 PM, Ceki Gulcu <ceki@qos.ch> wrote:
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@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 _______________________________________________ Logback-user mailing list Logback-user@qos.ch http://qos.ch/mailman/listinfo/logback-user
participants (4)
-
Ceki Gulcu -
David Zeigler -
david_z
-
Ralph Goers