Hi Nicko,
Thanks for responding to this one.
At first, I was resistant to a separate method (DebugFormat) instead of
the familiar Debug (plus overloads). But now that I've had some time to
think on it, it makes sense for several reasons:
- Intent.
- The API makes it explicit if the user wants the string
to be 'formatted' or not
- Speed.
- Leaves conventional interface methods untouched with
no need to analyze what the right behavior should be, thus keeping them
fast.
- It eliminates a lot of conversion logic which would
otherwise be needed to analyze and provide backward compatibility.
- Simplicity.
- The 'new' implementation can be very simple, becoming
just a direct call to string.Format
- Consistency.
- As you mention, modeling after
StringBuilder.AppendFormat fits the C# language paradigm well
I don't see a need to include Exception as a separate argument, since it
can be passed as a parameter. Am I missing something here? Seems that
having it as the first parameter is confusing for users since most would
try to pass it as a parameter. Maybe there is something special
(related to ExceptionLayout) that is being done above what we get via
Exception.ToString that log4net performs and you are trying to preserve
this logic? Is there any way to test the parameters and automatically
grab the exeception if needed?
Assuming Exception.ToString is sufficient, adding the first two of the
methods you mention would suffice and be much less confusing:
void DebugFormat(string format, params object[] args);
void DebugFormat(IFormatProvider provider, string format, params
object[] args);
-Doug
-----Original Message-----
From: Nicko Cadell [mailto:[EMAIL PROTECTED]
Sent: Sunday, September 12, 2004 9:55 AM
To: Log4NET Dev
Subject: RE: New code to allow formatting during logging
Doug,
Supporting the String.Format syntax is something that has been requested
before. I have resisted it for a number of reasons, however it does
appear as though the convenience and familiarity of the syntax to .NET
developers may outweigh my concerns.
Your implementation seems as though it is doing too much work to force
the new syntax into the current interface. How about we add new methods
along the lines of the StringBuilder Append & AppendFormat.
We need to allow an optional IFormatProvider to be specified as well as
the optional Exception. The method syntax would be:
void DebugFormat(string format, params object[] args);
void DebugFormat(IFormatProvider provider, string format, params
object[] args);
void DebugFormat(Exception exception, string format, params object[]
args);
void DebugFormat(Exception exception, IFormatProvider provider, string
format, params object[] args);
And so on for the other levels.
Can you see anything wrong with enhancing the interface like this?
Nicko
> -----Original Message-----
> From: de la Torre, Douglas [mailto:[EMAIL PROTECTED]
> Sent: 08 September 2004 02:06
> To: Log4NET Dev
> Subject: New code to allow formatting during logging
>
> Hi All,
>
> I'm including code that would allow the logging methods to work like
> Console.WriteLine or string.Format.
>
> For example, the changes below make it convenient to do something
> like:
>
> log.Debug( "message with params {0} and {1}", param1, param2 )
>
> without needing to use string.Format
>
> log.Debug( string.Format( "message with params {0} and {1}",
param1,
> param2 ) )
>
> Since string.Format is null-friendly and also has the potential to
> defer string-building overhead until the string is actually consumed,
> I noticed I had written many logging statements in my own code that
> look like this:
>
> if( log.IsDebugEnabled ) log.Debug( string.Format( "message with
> params {0} and {1}", param1, param2 ) )
>
> The changes below can be applied to the LogImpl class, to give it the
> ability to absorb the functionality of string.Format to make this
> easier and let me eliminate lots of duplication.
>
> I included unit tests and also checked to see that it is backward
> compatible with the existing calls that currently pass a message and
> exception.
>
> Note 1) For this to work, the ILog interface would need to add the
> methods that take the params, and remove the methods that take an
> exception, otherwise when someone passes a message with {0} and a
> single parameter with an exception, the specific method will be called
> rather than the generic one taking params, and thus no formatting
> substitution would occur.
>
> Note 2) If the ILogger object doesn't use
> Exception.ToString() then using the format specifier {0} would
> potentially produce a different result than calling a method like
> Debug( message, ex ). In cases where the exception is the sole
> parameter, since it falls back, no change would be seen. Only new
> code that introduced two exceptions would see this. Assuming the
> ToString method of the exception is used, this is a non-issue.
>
> What do you think? Is the output formatting code below useful?
>
> -Doug
>
> Doug de la Torre
> Lead Developer
> UGS
>
>
>
> ------------------
>
> using System;
> using System.Collections;
>
> using log4net;
> using log4net.spi;
>
> #if NUNIT_TESTS
> using NUnit.Framework;
> #endif
>
> namespace Log4netWrappers
> {
> /// <summary>
> /// Placeholder class to put a 'new' implementation of the
LogImpl
> code.
> ///
> /// Note that the main purpose of this class is to remove the
> overloaded
> /// methods that previously took an exception as a separate
> parameter,
> /// and roll this functionality into a more generic method that
takes
> /// arbitrary parameters, like <see cref="string.Format"/> does.
> ///
> /// These changes make it convenient to do something like:
> ///
> /// log.Debug( "message with params {0} and {1}",
> "param1", "param2" )
> ///
> /// without needing to use
> ///
> /// log.Debug( string.Format( "message with params
> {0} and {1}", "param1", "param2" ) )
> ///
> /// and replace the previous method that took a message and
> an exception
> /// </summary>
> public class MyLogImpl
> {
> ILogger logger;
>
> string m_fullName;
>
> /// <summary>
> /// Constructor
> /// </summary>
> /// <param name="logger"></param>
> public MyLogImpl( ILogger logger )
> {
> this.logger = logger;
> this.m_fullName = base.GetType().FullName;
> }
>
> public ILogger Logger
> {
> get
> {
> return logger;
> }
> }
>
> public void Debug(object message)
> {
> this.Logger.Log(this.m_fullName,
> Level.DEBUG, message, null);
> }
>
> public void Info(object message)
> {
> this.Logger.Log(this.m_fullName,
> Level.INFO, message, null);
> }
>
> public void Warn(object message)
> {
> this.Logger.Log(this.m_fullName,
> Level.WARN, message, null);
> }
>
> public void Error(object message)
> {
> this.Logger.Log(this.m_fullName,
> Level.ERROR, message, null);
> }
>
> public void Fatal(object message)
> {
> this.Logger.Log(this.m_fullName,
> Level.FATAL, message, null);
> }
>
> #region Methods that are no longer needed
>
> // public void Debug(object message,
> Exception t)
> // {
> // this.Logger.Log(this.m_fullName,
> Level.DEBUG, message, t);
> // }
> //
> // public void Info(object message,
> Exception t)
> // {
> // this.Logger.Log(this.m_fullName,
> Level.INFO, message, t);
> // }
> //
> // public void Warn(object message,
> Exception t)
> // {
> // this.Logger.Log(this.m_fullName,
> Level.WARN, message, t);
> // }
> //
> // public void Error(object message,
> Exception t)
> // {
> // this.Logger.Log(this.m_fullName,
> Level.ERROR, message, t);
> // }
> //
> // public void Fatal(object message,
> Exception t)
> // {
> // this.Logger.Log(this.m_fullName,
> Level.FATAL, message, t);
> // }
>
> #endregion
>
> #region New methods that replace the single exception
parameter, and
> allow arbitrary params
>
> public void Debug( object message, params object[]
parameters )
> {
> LogFormatted( Level.DEBUG, message, parameters
);
> }
>
> public void Info( object message, params object[]
parameters )
> {
> LogFormatted( Level.INFO, message, parameters );
> }
>
> public void Warn( object message, params object[]
parameters )
> {
> LogFormatted( Level.WARN, message, parameters );
> }
>
> public void Error( object message, params object[]
parameters )
> {
> LogFormatted( Level.ERROR, message, parameters
);
> }
>
> public void Fatal( object message, params object[]
parameters )
> {
> LogFormatted( Level.FATAL, message, parameters
);
> }
>
> #endregion
>
> /// <summary>
> /// This method does the work of combining the
previously supported
> method that
> /// took an exception, now allowing arbitrary params and
supporting
> formatting.
> ///
> /// This makes it convenient to do something like:
> ///
> /// log.Debug( "message with params {0} and
> {1}", "param1", "param2" )
> ///
> /// without needing to use
> ///
> /// log.Debug( string.Format( "message with
> params {0} and {1}", "param1", "param2" ) )
> ///
> /// </summary>
> /// <param name="level"></param>
> /// <param name="message"></param>
> /// <param name="parameters"></param>
> private void LogFormatted( Level level, object message,
params
> object[] parameters )
> {
> //
> // Optimization to avoid
> string-building penalty if logging is not enabled
> // at the requested level
> //
> if( false == this.Logger.IsEnabledFor( level ) )
> {
> return;
> }
>
> if( null == parameters || 0 ==
> parameters.Length )
> {
> this.Logger.Log(
> this.m_fullName, level, message, null );
> return;
> }
>
> if( 1 == parameters.Length )
> {
> System.Exception ex =
> parameters[0] as System.Exception;
> if( null != ex )
> {
> if( false ==
> MessageRequiresFormatting( message ) )
> {
> this.Logger.Log(
> this.m_fullName, level, message, ex );
> return;
> }
>
> // String contains formatting
> specifier. Fall through to allow in-line formatting
> }
> }
>
> string formatString =
> CreateFormatString( message );
> string formatted = string.Format(
> formatString, parameters );
> this.Logger.Log(this.m_fullName, level,
formatted, null);
> }
>
> private bool MessageRequiresFormatting( object message )
> {
> // If either of these conditions
> occurs, we can log the string directly
> // and return without needing to call
string.Format
> //
> // 1) The message is not a string
> // 2) The message is a string, but doesn't
contain embedded
> formatting characters {0}
>
> string messageAsString = message as string;
> if( null == messageAsString || false ==
> ContainsFormattingSpecification( messageAsString ) )
> {
> return false;
> }
> return true;
> }
>
> private bool ContainsFormattingSpecification( string
message )
> {
> if( null != message )
> {
> if( -1 != message.IndexOf( "{0" ) )
> {
> return true;
> }
> }
> return false;
> }
>
> /// <summary>
> /// The format string is passed to <see
cref="string.Format"/>
> /// along with the input parameters to have it render a
display
> /// message
> /// </summary>
> /// <param name="message"></param>
> /// <returns></returns>
> private string CreateFormatString(object message)
> {
> string formatString = message as string;
> if( null == formatString )
> {
> if( null == message )
> {
> formatString = "";
> }
> else
> {
> formatString =
> message.ToString();
> }
> }
> return formatString;
> }
>
> #region NUnit Tests
> #if NUNIT_TESTS
> /// <summary>
> /// NUnit Tests
> /// </summary>
> [TestFixture] public class TestMyLogImpl : ILogger
> {
> string toString;
> ArrayList events;
>
> #region MessageEvent class
> /// <summary>
> /// Class to record logging event
> details when the event occurs
> /// </summary>
> private class MessageEvent
> {
> public log4net.spi.Level level;
> public object message;
> public System.Exception exception;
>
> /// <summary>
> /// Constructor
> /// </summary>
> /// <param name="level"></param>
> /// <param name="message"></param>
> public MessageEvent(
> log4net.spi.Level level, object message ) : this( level, message, null
> )
> {}
>
> /// <summary>
> /// Constructor
> /// </summary>
> /// <param name="level"></param>
> /// <param name="message"></param>
> /// <param name="exception"></param>
> public MessageEvent(
> log4net.spi.Level level, object message, System.Exception exception )
> {
> this.level = level;
> this.message = message;
> this.exception = exception;
> }
> }
> #endregion
>
> private void RecordMessage(
> log4net.spi.Level level, object message )
> {
> events.Add( new MessageEvent( level,
> message ) );
> }
>
> private void RecordMessage(
> log4net.spi.Level level, object message, System.Exception ex )
> {
> events.Add( new MessageEvent( level,
> message, ex ) );
> }
>
> #region ILogger Members
>
> public void Log(LoggingEvent logEvent)
> {
> throw new NotImplementedException();
> }
>
> public void Log(string callerFullName, Level
level, object message,
> Exception t)
> {
> RecordMessage( level, message, t );
> }
>
> public bool IsEnabledFor(Level level)
> {
> return true;
> }
>
> /// <summary>
> /// Fake the name for now
> /// </summary>
> public string Name
> {
> get
> {
> return "";
> }
> }
>
> /// <summary>
> /// Fake repository for now
> /// </summary>
> public log4net.Repository.ILoggerRepository
> Repository
> {
> get
> {
> return null;
> }
> }
>
> #endregion
>
> /// <summary>
> /// Allows us to create a test object that is
non-string based and
> /// supply a string in the ToString method call
> /// </summary>
> /// <returns></returns>
> public override string ToString()
> {
> return toString;
> }
>
> /// <summary>
> /// Does per-test initialization
> /// </summary>
> [SetUp] public void SetUp()
> {
> events = new ArrayList();
> toString = String.Empty;
> }
>
> /// <summary>
> /// Tests 3 cases -
> ///
> /// 1) Legacy, method call with
> message and no params, like log.Debug( message );
> /// 2) Legacy, method call with
> message and exception, like log.Debug( message, exception );
> /// 3) New, method call with formatted string
and variable number
> of parameters, log.Debug( messageToFormat, param1,
> param2 );
> /// </summary>
> [Test] public void TestDebugWithParams()
> {
> MyLogImpl wrapper = new
> MyLogImpl( this );
> Exception ex1 = new
> ApplicationException( "using Debug" );
> this.toString = "ToString test message";
>
> wrapper.Debug( "my {0} message,
> logged as Debug", "one-param" );
> wrapper.Debug( "single-param
> message, logged as Debug with exception and no formatting", ex1 );
> wrapper.Debug( "my {0} message,
> logged as Debug with params {1} and {2}", "multi-param", 3, 2.1 );
> wrapper.Debug( "my {0} message,
> logged as Debug with exception {1}", "multi-param", ex1 );
> wrapper.Debug( "single-param
> message, logged as Debug with exception {0} and formatting", ex1 );
> wrapper.Debug( "single-param
> message, logged as Debug with non-string param {0} and formatting",
> this );
> wrapper.Debug( null, "param1", "param2"
> );
>
> Assert.Equals( 7, events.Count );
>
> // Fallback - Existing method
> should be called for single message (no params)
> VerifyMessageEvent( (MessageEvent)
events[0],
> log4net.spi.Level.DEBUG, "my one-param message, logged as Debug" );
>
> // Fallback - this one should be
> backward compatible with existing methods that call Debug( object,
> exception )
> VerifyMessageEvent( (MessageEvent)
events[1],
> log4net.spi.Level.DEBUG, "single-param message, logged as Debug with
> exception and no formatting", ex1 );
>
> // New - methods with params
> should be supported now
> VerifyMessageEvent( (MessageEvent)
events[2],
> log4net.spi.Level.DEBUG, "my multi-param message, logged as Debug with
> params 3 and 2.1" );
> VerifyMessageEvent( (MessageEvent)
events[3],
> log4net.spi.Level.DEBUG, string.Format( "my multi-param message,
> logged as Debug with exception {0}", ex1 ) );
> VerifyMessageEvent( (MessageEvent)
events[4],
> log4net.spi.Level.DEBUG, string.Format( "single-param message, logged
> as Debug with exception {0} and formatting", ex1 ) );
> VerifyMessageEvent( (MessageEvent)
events[5],
> log4net.spi.Level.DEBUG, string.Format( "single-param message, logged
> as Debug with non-string param {0} and formatting", this
> ) );
> VerifyMessageEvent( (MessageEvent)
events[6],
> log4net.spi.Level.DEBUG, "" );
> }
>
> /// <summary>
> /// Similar to the Debug test, but checks to see
that the Info
> method is called instead
> ///
> /// Note this doesn't cover all the possible
test scenarios in the
> Debug method test,
> /// just some quick tests to make sure the right
method is getting
> called
> /// </summary>
> [Test] public void TestInfoWithParams()
> {
> MyLogImpl wrapper = new
> MyLogImpl( this );
> Exception ex1 = new
> ApplicationException( "using Info" );
>
> wrapper.Info( "my {0} message,
> logged as Info", "one-param" );
> wrapper.Info( "my {0} message,
> logged as Info with params {1} and {2}", "multi-param", 3, 2.1 );
> wrapper.Info( "my {0} message,
> logged as Info with exception {1}", "multi-param", ex1 );
> wrapper.Info( "single-param
> message, logged as Info with exception {0} and formatting", ex1 );
> wrapper.Info( "single-param
> message, logged as Info with exception and no formatting", ex1 );
>
> Assert.Equals( 5, events.Count );
>
> // Fallback - Existing method
> should be called for single message (no params)
> VerifyMessageEvent( (MessageEvent)
events[0],
> log4net.spi.Level.INFO, "my one-param message, logged as Info" );
>
> // Fallback - this one should be
> backward compatible with existing methods that call Debug( object,
> exception )
> VerifyMessageEvent( (MessageEvent)
events[4],
> log4net.spi.Level.INFO, "single-param message, logged as Info with
> exception and no formatting", ex1 );
>
> // New - methods with params
> should be supported now
> VerifyMessageEvent( (MessageEvent)
events[1],
> log4net.spi.Level.INFO, "my multi-param message, logged as Info with
> params 3 and 2.1" );
> VerifyMessageEvent( (MessageEvent)
events[2],
> log4net.spi.Level.INFO, string.Format( "my multi-param message, logged
> as Info with exception {0}", ex1 ) );
> VerifyMessageEvent( (MessageEvent)
events[3],
> log4net.spi.Level.INFO, string.Format( "single-param message, logged
> as Info with exception {0} and formatting", ex1 ) );
> }
>
> /// <summary>
> /// Tests that when the message string has the
opening brace { but
> no closing brace,
> /// an exception is thrown. This is because the
format method
> expects {0} as a
> /// parameter.
> /// </summary>
> [ExpectedException( typeof( FormatException ) )]
> [Test] public void
> TestDebugWithParams_InvalidFormatThrowsException()
> {
> MyLogImpl wrapper = new
> MyLogImpl( this );
> Exception ex1 = new
> ApplicationException( "using Debug" );
> wrapper.Debug( "my { message,
> logged as Debug", "one-param" );
> }
>
> /// <summary>
> /// Assumes exception is not present
> /// </summary>
> /// <param name="messageEvent"></param>
> /// <param name="expectedLevel"></param>
> /// <param name="expectedMessage"></param>
> private void VerifyMessageEvent(
> MessageEvent messageEvent, log4net.spi.Level expectedLevel, string
> expectedMessage, Exception expectedException )
> {
> Assert.Equals( expectedLevel,
> messageEvent.level );
> Assert.Equals( expectedMessage,
> messageEvent.message );
> Assert.Same( expectedException,
> messageEvent.exception );
> }
>
> /// <summary>
> /// Assumes exception is not present
> /// </summary>
> /// <param name="messageEvent"></param>
> /// <param name="expectedLevel"></param>
> /// <param name="expectedMessage"></param>
> private void VerifyMessageEvent(
> MessageEvent messageEvent, log4net.spi.Level expectedLevel, string
> expectedMessage )
> {
> Assert.Equals( expectedLevel,
> messageEvent.level );
> Assert.Equals( expectedMessage,
> messageEvent.message );
> Assert.Null( messageEvent.exception );
> }
> }
> #endif
> #endregion
> }
> }
>
