0

我一直在审查和重构一位同事的代码,用于开发执行一组作业的控制台应用程序。我想就如何改进系统的入口点提出意见,感觉它可能会更健壮一些。我们使用 NLog 进行日志记录,它被配置为自动显示在控制台和日志文件上。同样,我必须catch (Exception ex)尝试干净地处理并记录任何漏掉的异常——理论上它不应该被击中,但最好尽可能干净地处理这些事情。

{0}:对每次_logger.Info()调用开始时的日志记录风格特别不满意,但如果像这样重构为自己的函数LogMe(methodName, "text to be logged"),我并没有真正节省那么多打字。请记住,我故意省略了使线程保持活动状态的代码等。这超出了我正在寻找的范围。

是否可以改进以下内容,或者这是否可以在没有大量努力/重构的情况下合理地“好”?

static void Main(string[] args)
{
    string methodName = string.Format("{0}.Main()", typeof(Program).FullName);
    try
    {
        _logger.Info("{0}: Launched", methodName);
        IKernel kernel = IOC.SetupKernel();

        _logger.Info("{0}: Reading job schedules from the configuration file");
        JobScheduleSection scheduleSection = (JobScheduleSection)ConfigurationManager.GetSection("jobScheduleSection");
        if (scheduleSection == null)
        {
            _logger.Warn("{0}: No job schedule section found in configuration file", methodName);
            return;
        }

        List<IJobSchedule> schedules = scheduleSection.JobSchedules.ToList();
        if (schedules == null)
        {
            _logger.Info("{0}: No job schedules found", methodName);
            return;
        }
        _logger.Info("{0}: Found {1} job schedules", methodName, schedules.Count);

        _logger.Info("{0}: Kicking Launcher...", methodName);
        Launcher launcher = new Launcher(kernel, schedules);
        launcher.LaunchSchedulerService();
    }
    catch (Exception ex)
    {
        _logger.ErrorException(string.Format("{0}: An unhandled exception occurred", methodName), ex);
    }
    finally
    {
        _logger.Info("{0}: Exited. Program complete.");
    }
}
4

3 回答 3

3

我这样做的方法是为 NLog 创建一个包装类,它将包装每个日志方法,并混淆 methodName 并使用 StackTrace 对象来获取方法名称。那你就不用每次都写了;调用 Logging 包装器方法的方法的方法名称是自动注入的。

它会看起来更干净,因为您不会到处都有 {0} 和 methodName。

您甚至可以更进一步,创建一个日志包装类,该类接受日志字符串和一个动作,执行该动作,并使用 StackTrace 对象一次性调用日志对象。

我已经使用它来执行时间操作并记录它们,一次调用即可完成所有操作并节省重复代码。我的方法 ExecuteTimedAction(string logString, Action actionToExecute) 使用秒表,记录开始字符串,启动秒表,执行方法(Action 委托),停止秒表,并再次记录两个日志,其中包含时间戳、程序集名称,以及发起调用的方法的名称。

获取方法的代码很简单,使用StackTrace对象,获取上一次调用的StackFrame。

        var stackTrace = new StackTrace();
        var callingMethodName = stackTrace.GetFrame(2).GetMethod().Name;

注意我上面有 2 个硬编码,但那是因为额外的包装器调用;如果您直接调用,那么您可能需要 GetFrame(1)。最好的方法是使用即时窗口并尝试不同的帧,或者使用 StackTrace 对象的 GetFrames() 方法循环浏览它以查看您得到的内容。

我现在正在考虑保留字符串格式的参数并为日志包装器附加第一个参数。可以这样做:

public static class LogWrapper
{
    private static Logger _logger // where Logger assumes that is the actual NLog logger, not sure if it is the right name but this is for example

    public static void Info(string logString, object[] params)
    {
        // Just prepend the method name and then pass the string and the params to the NLog object
        _logger.Info(
            string.Concat(
                GetMethodName(),
                ": ",
                logString
            ),
            params
        );
    }

    public static void Warn(string logString, object[] params)
    {
        // _logger.Warn(
        //  You get the point ;)
        // )
    }

    private static string GetMethodName()
    {
        var stackTrace = new StackTrace(); // Make sure to add using System.Diagnostics at the top of the file
        var callingMethodName = stackTrace.GetFrame(2).GetMethod().Name; // Possibly a different frame may have the correct method, might not be 2, might be 1, etc.
    }
}

然后在您的调用代码中,_logger 成员变为 LoggerWrapper,而不是 Logger,并且您以完全相同的方式调用它,但您从代码中删除了 {0}。您需要检查空值,也许如果没有其他参数,则有一个方法重载,只在没有参数的情况下调用;我不确定 NLog 是否支持,所以你必须检查一下。

... 编辑:

只是为了兴趣点,我在可能被一堆程序集引用的公共库类型程序集中使用这种类型的代码,因此我可以获得调用程序集、方法名称等信息,而无需对其进行硬编码或担心它在我的日志记录代码中。它还确保使用该代码的其他任何人都不必担心它。他们只需调用 Log() 或 Warn() 或其他任何方法,程序集就会自动保存在日志中。

这是一个例子(我知道你说对你来说太过分了,但如果你可能需要这样的东西的话,可以为未来思考)。在此示例中,我只记录程序集,而不是方法名称,但它可以轻松组合。

    #region :           Execute Timed Action                        :

    public static T ExecuteTimedAction<T>(string actionText, Func<T> executeFunc)
    {
        return ExecuteTimedAction<T>(actionText, executeFunc, null);
    }

    /// <summary>
    /// Generic method for performing an operation and tracking the time it takes to complete (returns a value)
    /// </summary>
    /// <typeparam name="T">Generic parameter which can be any Type</typeparam>
    /// <param name="actionText">Title for the log entry</param>
    /// <param name="func">The action (delegate method) to execute</param>
    /// <returns>The generic Type returned from the operation's execution</returns>

    public static T ExecuteTimedAction<T>(string actionText, Func<T> executeFunc, Action<string> logAction)
    {
        string beginText = string.Format("Begin Execute Timed Action: {0}", actionText);

        if (null != logAction)
        {
            logAction(beginText);
        }
        else
        {
            LogUtil.Log(beginText);
        }

        Stopwatch stopWatch = Stopwatch.StartNew();
        T t = executeFunc(); // Execute the action
        stopWatch.Stop();

        string endText = string.Format("End Execute Timed Action: {0}", actionText);
        string durationText = string.Format("Total Execution Time (for {0}): {1}", actionText, stopWatch.Elapsed);

        if (null != logAction)
        {
            logAction(endText);
            logAction(durationText);                
        }
        else
        {
            LogUtil.Log(endText);
            LogUtil.Log(durationText);
        }

        return t;
    }

    public static void ExecuteTimedAction(string actionText, Action executeAction)
    {
        bool executed = ExecuteTimedAction<bool>(actionText, () => { executeAction(); return true; }, null);
    }

    /// <summary>
    /// Method for performing an operation and tracking the time it takes to complete (does not return a value)
    /// </summary>
    /// <param name="actionText">Title for the log entry</param>
    /// <param name="action">The action (delegate void) to execute</param>

    public static void ExecuteTimedAction(string actionText, Action executeAction, Action<string> logAction)
    {
        bool executed = ExecuteTimedAction<bool>(actionText, () => { executeAction(); return true; }, logAction);
    }

    #endregion

然后日志函数看起来像这样,你可以看到我的日志函数没有硬编码到 ExecuteTimedAction 中,所以我可以将任何日志操作传递给它。

在日志类中,我将条目程序集名称保存在一个静态变量中,并将其用于所有日志......

private static readonly string _entryAssemblyName = Assembly.GetEntryAssembly().GetName().Name;

希望这能让您在重构方面有足够的思考空间!

于 2013-03-05T15:26:23.307 回答
2

我不是特别喜欢这种包装 NLog 的方式。GetMethodName 没有理由。NLog 能够自动提供方法名和类名(通过正确配置 Layout)。在包装 NLog(或 log4net)时,关键是根据 NLog.Logger.Log 实现日志记录方法(Info、Trace、Debug)。Log 的参数之一是记录器的类型(即 NLog 包装器的类型)。当 NLog 想要写出方法名时,它会简单地向上遍历堆栈跟踪,直到找到该类型。这将是“记录器”和应用程序之间的边界。堆栈跟踪再上一步,您可以从中获取调用站点的堆栈。NLog 可以记录方法名和类名。

此外,静态 NLog 包装器的问题是您失去了拥有记录器名称的能力。通常,检索记录器的模式是在您可能想要记录的每个类中都有这样的代码:

public class MyClassFromWhichIWantToLog
{
  private static readonly Logger _logger = LogManager.GetCurrentClassLogger();

  public void DoSomething()
  {
    _logger.Info("Hello!");
  }
}

LogManager.GetCurrentClassLogger 返回一个 Logger 实例,其“name”是类的完全限定类名。因为我们使用静态类变量来保存记录器,所以每种类型都有一个记录器实例(即 MyClassFromWhichIWantToLog 的所有实例将共享同一个记录器实例)。因为记录器以其类命名,所以您可以更好地控制日志输出的生成方式。您可以配置 NLog(通过 NLog.config),以便所有记录器始终记录。或者您可以将其配置为仅记录某些记录器(或某些记录器在一个级别记录,而其他记录器在不同级别记录)。假设您有一个包含各种组件的程序。它们似乎都工作正常,但您必须实现一个新组件。在开发过程中,您可能希望将其日志记录方式调高(即获取更多信息),同时将程序的其他部分调低(即从您的程序运行正常的部分获取最少的信息)。此外,您可以通过记录器名称重定向您的日志记录(例如,将来自某个类或命名空间的所有日志记录消息发送到某个日志记录目标(如果您正在调试程序的那一部分,则可能是调试器目标)并发送其他(包括那些将调试器)到您的输出文件或数据库)。如果你有一个静态记录器包装器,你就失去了在每个类或每个命名空间的基础上控制你的日志记录的能力。您可以通过记录器名称重定向您的日志记录(例如,将来自某个类或命名空间的所有日志记录消息发送到某个日志记录目标(如果您正在调试程序的那部分,则可能是调试器目标)并发送其他(包括那些去调试器的) ) 到您的输出文件或数据库)。如果你有一个静态记录器包装器,你就失去了在每个类或每个命名空间的基础上控制你的日志记录的能力。您可以通过记录器名称重定向您的日志记录(例如,将来自某个类或命名空间的所有日志记录消息发送到某个日志记录目标(如果您正在调试程序的那部分,则可能是调试器目标)并发送其他(包括那些去调试器的) ) 到您的输出文件或数据库)。如果你有一个静态记录器包装器,你就失去了在每个类或每个命名空间的基础上控制你的日志记录的能力。

看看我对这个问题的回答:

包装 NLog 时如何保留调用点信息

我的回答提供了维护正确呼叫站点信息的 NLog 包装器的源代码(直接来自 NLog 的源存储库)。请注意,来自 NLog 的示例更多的是说明如何扩展 NLog.Logger(通过添加“EventID”)而不是包装它。如果您忽略 EventID 的内容,您将看到关键是将包装器的类型传递给 NLog 的 Logger.Log 方法。

这是一个非常精简的 NLog 包装器(只有一个方法 (Info)),它应该正确地包装 NLog,以便保留调用站点信息。

  public class MyLogger
  {
    public MyLogger(Logger logger)
    {
      _logger = logger;
    }

    private Logger _logger;
    private void WriteMessage(LogLevel level, string message)
    {
      //
      // Build LogEvent here...
      //
      LogEventInfo logEvent = new LogEventInfo(logLevel, context.Name, message);
      logEvent.Exception = exception;

      //
      // Pass the type of your wrapper class here...
      //
      _logger.Log(typeof(MyLogger), logEvent);
    }

    public void Info(string message)
    {
      WriteMessage(LogLevel.Info, message);
    }
  }

你会像这样使用它:

public class MyClassWhereIWantToUseLogging
{
  private static readonly _logger = new MyLogger(LogManager.GetCurrentClassLogger());

  public void DoSomething()
  {
    _logger.Info("Hello!"); //If you log call site info, you should class name and method name.
  }
}

有关更多 NLog 信息,请参阅这个流行的(如果我自己这么说的话 ;-))NLog 帖子:

最有用的 NLog 配置

于 2013-03-08T22:00:57.453 回答
1

更新

我找到了一个更简洁的解决方案,而不是尝试扩展 NLog 类或以其他方式创建方法/方法重载。NLog 支持将以下字段添加到NLog.config与您的应用程序一起部署的文件中;

layout="${callsite}"

这可以应用于适合您的任何目标,CSV、控制台、电子邮件等。在 CSV 中,配置如下;

<target name="CSVFile" xsi:type="File"  fileName="${basedir}/Logging/BullorBear.Identity.API-${date:format=yyyy-MM-dd}.csv" 
        archiveEvery="Day" maxArchiveFiles="28">
  <layout xsi:type="CSVLayout">
    <column name="Index" layout="${counter}" />
    <column name="Time" layout="${longdate}" />
    <column name="Callsite" layout="${callsite}" />
    <column name="Severity" layout="${level:uppercase=true}" />
    <column name="Detail" layout="${message}" />
    <column name="Exception" layout="${exception:format=ToString}" />
  </layout>
</target>

输出;

Index,Time,Callsite,Severity,Detail,Exception
1,2013-03-12 12:35:07.6890,ProjectName.Controllers.SomeController.SomeMethod,INFO,Authenticating...,
于 2013-03-12T12:38:58.853 回答