How to use params keyword along with caller Inform

问题:

I am trying to combine the C# 5.0 Caller Information along with the C# params keyword. The intention is to create a wrapper for a logging framework, and we want the logger to format the text like String.Format. In previous versions, the method looked like this:

void Log(
   string message,
   params object[] messageArgs = null);

And we call it like this:

log.Log("{0}: I canna do it cap'n, the engines can't handle warp {1}!", 
        "Scotty", warpFactor);

Now, we want to capture caller information and log that as well. So the signature becomes:

void Log(
    string message,
    params object[] messageArgs,
    [CallerMemberName] string sourceMemberName = null);

That doesn't compile because the params must be last parameter. So I try this:

void Log(
    string message,
    [CallerMemberName] string sourceMemberName = null,
    params object[] messageArgs);

Is there a way to call that without either providing sourceMembername, or assigning the messageArgs argument explicitly as a named parameter? Doing so defeats the purpose of the params keyword:

// params is defeated:
log.Log("message", 
        messageArgs: new object[] { "Scotty", warpFactor });
// CallerMemberName is defeated:
log.Log("message", null,
        "Scotty", warpFactor);

Is there a way to do this? It seems like the "hacky" way the caller information is passed precludes using the params keyword. It would be awesome if the C# compiler recognized that the caller member information parameters aren't really parameters at all. I can see no need to ever pass them explicitly.

My backup will be to skip the params keyword, and the caller will have to use the long signature in that last example.

回答1:

I don't think that it can be done in exactly the way you want to do it. However, I could think of a few viable workarounds which would probably give you almost the same benefits.

1. Use an intermediate method call to capture the caller member name. The first method call returns a delegate which can in turn be called to provide the additional parameters. This looks weird, but it should work:

   log.Log()("{0}: I canna do it cap'n, the engines can't handle warp {1}!", 
   "Scotty", warpFactor);
   

   One disadvantage here is that it's possible to call log.Log("something"), expecting that your message will be logged, and nothing will happen. If you use Resharper, you can mitigate this by adding a [Pure] attribute to the Log() method so you get a warning if someone doesn't do anything with the resulting object. You could also tweak this approach slightly, saying:

   var log = logFactory.GetLog(); // <--injects method name.
   log("{0}: I canna do it cap'n, the engines can't handle warp {1}!", 
       "Scotty", warpFactor);
   

2. Produce your log messages with lambdas, and let string.Format take care of the params array:

   log.Log(() => string.Format("{0}: I canna do it cap'n, the engines can't handle warp {1}!", 
       "Scotty", warpFactor));
   

   This is the approach that I typically use, and it has some side advantages:

   1. Your log method can catch exceptions produced while producing the debug string, so instead of breaking your system you just get an error that says: "Failed to produce log message: [exception details]".

   2. Sometimes the object you pass to your format string might incur additional cost, which you'd only want to incur when you need it:

      log.Info(() => string.Format("{0}: I canna do it cap'n, the engines can't handle warp {1}!", 
          _db.GetCurrentUsername(), warpFactor));
      

      You'd prefer not to have the above code do a database trip if info-level logging is not turned on.

   As a side note, I find myself using string.Format often enough that I've created a helper method to shorten the syntax slightly:

   log.Log(() => "{0}: I canna do it cap'n, the engines can't handle warp {1}!" 
       .With("Scotty", warpFactor));
   

回答2:

To go along with StriplingWarrior suggestion instead of a delegate you could do it with a fluent syntax.

public static class Logger
{
    public static LogFluent Log([CallerMemberName] string sourceMemberName = null)
    {
        return new LogFluent(sourceMemberName);
    }
}

public class LogFluent
{
    private string _callerMemeberName;

    public LogFluent(string callerMamberName)
    {
        _callerMemeberName = callerMamberName;
    }

    public void Message(string message, params object[] messageArgs)
    {

    }
}

Then call it like

Logger.Log().Message("{0}: I canna do it cap'n, the engines can't handle warp {1}!", "Scotty", 10);

Logger doesn't have to be static but it was a simple way to demonstrate the concept

回答3:

Well, let me mention one option; you can use reflection to get exact same name, as CallMemberName. This will be definitely slower. Assuming you don't log every millisecond, it will be enough to handle the pressure, I believe.

var stackTrace = new StackTrace(); var methodName = stackTrace.GetFrame(1).GetMethod().Name;

回答4:

I like following Jim Christophers (@beefarino) pluralsight course to setup my own logging projects. For that I clone the ILog interface as ILogger, I implement that - lets say in a class called LoggerAdapter - and then I use Jim Christophers LogManager to have a GetLogger(Type type)-Method that returns a wrapped log4net-logger 'LoggerAdapter':

namespace CommonLogging
{
    public class LogManager : ILogManager
    {
        private static readonly ILogManager _logManager;

        static LogManager()
        {
            log4net.Config.XmlConfigurator.Configure(new FileInfo("log4net.config"));
            _logManager = new LogManager();
        }

        public static ILogger GetLogger<T>()
        {
            return _logManager.GetLogger(typeof(T));
        }

        public ILogger GetLogger(Type type)
        {
            var logger = log4net.LogManager.GetLogger(type);
            return new LoggerAdapter(logger);
        }
    }
}

The next step is to create a generic extension like this, setting the caller-information into a ThreadContext.Property:

public static class GenericLoggingExtensions
{
    public static ILogger Log<TClass>(this TClass klass, [CallerFilePath] string file = "", [CallerMemberName] string member = "", [CallerLineNumber] int line = 0)
        where TClass : class
    {
        ThreadContext.Properties["caller"] = $"[{file}:{line}({member})]";
        return LogManager.GetLogger<TClass>();
    }
}

Having that in place I can always call up a logger before writing an actual method by just calling:

this.Log().ErrorFormat("message {0} {1} {2} {3} {4}", "a", "b", "c", "d", "e");

and if you have the conversionPattern of your PatternLayout configured to use the property:

<layout type="log4net.Layout.PatternLayout">
  <conversionPattern value="%utcdate [%thread] %-5level %logger - %message - %property{caller}%newline%exception" />
</layout>

you will always have a proper output with callerinformation of the first .Log()-call:

2017-03-01 23:52:06,388 [7] ERROR XPerimentsTest.CommonLoggingTests.CommonLoggingTests - message a b c d e - [C:\git\mine\experiments\XPerimentsTest\CommonLoggingTests\CommonLoggingTests.cs:71(Test_Debug_Overrides)]