Как улучшить точку входа в консольное приложение

Я просматривал и рефакторинг кода коллеги для разработки консольного приложения, которое выполняет набор заданий. Я хотел бы услышать мнения о том, как улучшить точку входа в систему, которая кажется более надежной. Мы используем NLog для ведения журнала, который настроен на автоматическое отображение на консоли, а также в файле журнала. Точно так же у меня есть catch (Exception ex), чтобы попытаться аккуратно обработать и зарегистрировать любые исключения, которые проскальзывают - теоретически он никогда не должен срабатывать, но всегда лучше обрабатывать эти вещи чисто, где это возможно.

Я особенно недоволен стилем ведения журнала, когда в начале каждого вызова _logger.Info() есть {0}:, но если реорганизовать его в собственную функцию, например 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.");
    }
}

person DiskJunky    schedule 05.03.2013    source источник
comment
Интересно, подходит ли это лучше всего для обмена стеками Code Review: codereview.stackexchange.com ....   -  person Arran    schedule 05.03.2013
comment
@Arran, возможно, но я не собираюсь пересматривать его точно, но я перенесу его, если попросят   -  person DiskJunky    schedule 05.03.2013


Ответы (3)


Я сделал это так, чтобы создать класс-оболочку для NLog, который будет обертывать каждый метод журнала, скрывать имя метода и использовать объект StackTrace для получения имени метода. Тогда вам не придется писать это каждый раз; имя метода, вызывающего метод-оболочку Logging, вводится автоматически.

Это будет выглядеть чище, так как у вас не будет везде {0} и methodName.

Вы можете сделать еще один шаг вперед и создать класс-оболочку ведения журнала, который принимает строку журнала и действие, выполняет действие и вызывает объект журнала, используя объект StackTrace, и все это за один раз.

Я использовал это для выполнения временных действий и их регистрации, удобно делать все за один вызов и экономить на повторяющемся коде. Мой метод ExecuteTimedAction(string logString, Action actionToExecute) использует секундомер, регистрирует стартовую строку, запускает секундомер, выполняет метод (делегат действия), останавливает секундомер и снова регистрирует оба журнала с отметкой времени, именем сборки и имя метода, из которого инициирован вызов.

Код для получения метода прост: используйте объект StackTrace и получите StackFrame предыдущего вызова.

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

Примечание. У меня есть 2 жестко закодированных выше, но это из-за дополнительного вызова оболочки; если вы звоните напрямую, вам может понадобиться GetFrame(1). Лучший способ - использовать непосредственное окно и попробовать разные кадры или просто просмотреть его, чтобы увидеть, что вы получите, используя метод GetFrames() объекта StackTrace.

Сейчас я изучаю сохранение параметров для строкового формата и добавление первого параметра для оболочки журнала. Это можно сделать примерно так:

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, поэтому я могу передать ей любое действие журнала.

В классе журнала я сохраняю имя сборки Entry один раз в статической переменной и использую ее для всех журналов...

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

Надеюсь, это даст вам достаточно пищи для размышлений о рефакторинге!

person Dmitriy Khaykin    schedule 05.03.2013
comment
интересный подход к обертыванию регистратора - у вас есть краткий пример кода? Подход с секундомером немного излишен для того, что нам нужно, но это определенно то, что я буду иметь в виду для более атомарных разделов, основанных на задачах, поскольку регистратор уже настроен для регистрации даты/времени для каждой записи. - person DiskJunky; 05.03.2013
comment
интересный! Какова производительность хит на этом или есть один? Возникает ли исключение, если проект скомпилирован для выпуска? - person DiskJunky; 05.03.2013
comment
Просто добавил несколько образцов. Понятия не имею о снижении производительности, но если ведение журнала и удобочитаемость/обслуживание кода важнее, чем производительность, вам нужно позвонить, если оно того стоит. Основные накладные расходы связаны с использованием объекта stackFrame, но я никогда не проверял его. Это делает код намного более читабельным, и, поскольку я не пишу приложения для торговли акциями, я думаю, что небольшой удар может быть приемлемым. Это всегда компромисс в программировании. - person Dmitriy Khaykin; 05.03.2013
comment
@DiskJunky - хорошо, я думаю, что добавил достаточно, чтобы воспользоваться некоторыми идеями :) удачи. - person Dmitriy Khaykin; 05.03.2013

Мне не особенно нравится такой способ упаковки NLog. Нет причин для GetMethodName. NLog имеет возможность автоматически предоставлять имя метода и имя класса (путем правильной настройки макета). При обертывании NLog (или, если уж на то пошло, log4net) ключевым моментом является реализация методов ведения журнала (Info, Trace, Debug) с точки зрения NLog.Logger.Log. Одним из параметров журнала является тип регистратора (т. е. тип оболочки NLog). Когда NLog хочет записать имя метода, он просто просматривает трассировку стека, пока не найдет этот тип. Это будет граница между «регистратором» и приложением. Еще один шаг вверх по трассировке стека, и вы сможете получить стек для сайта вызова. С помощью этого NLog может регистрировать имя метода и имя класса.

Кроме того, проблема со статической оболочкой NLog заключается в том, что вы теряете возможность иметь имя регистратора. Как правило, шаблон для извлечения регистратора состоит в том, чтобы иметь подобный код в каждом классе, из которого вы можете захотеть вести журнал:

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

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

LogManager.GetCurrentClassLogger возвращает экземпляр Logger, чье «имя» является полным именем класса класса. Поскольку мы используем статическую переменную класса для хранения регистратора, для каждого типа существует один экземпляр регистратора (т. е. все экземпляры MyClassFromWhichIWantToLog будут совместно использовать один и тот же экземпляр Logger). Поскольку регистратор назван в честь своего класса, у вас гораздо больше контроля над тем, как генерируется вывод журнала. Вы можете настроить 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

person wageoghe    schedule 08.03.2013

Обновить

Я нашел гораздо более чистое решение вместо того, чтобы пытаться расширить класс 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...,
person DiskJunky    schedule 12.03.2013