MS Dynamics CRM и PostSharp

Приветствую, Уважаемые Хаброчитатели

В данной статье хочу поведать о результатах моих исследований относительно применимости PostSharp к MS Dynamics CRM в плане логирования.


Итак, имеется:

• MS Dynamics CRM 2013
• NLog
• PostSharp

Что хочу: логирование хочу (банально, но именно логирование).

Решил, что буду пробовать применить логирование к плагину для MS Dynamics CRM.

От логирования хочу следующее:

• Логировать метод, который был вызван
• Логировать входные аргументы
• Логировать, когда метод был завершен
• Логировать исключения

Для начала создадим проект для нашего плагина:



Подгрузим nuget-пакет с NLog:



Не забываем подцепить собственно PostSharp:



Также подцепляем сборки CRM SDK.

Теперь самое интересное: где хранить настройки логера?
Признаюсь честно, для меня это поныне открытый вопрос.
На ум приходят всего три варианта:

• Хардкод — плохой вариант
• В случае плагинов — в конфигурации плагина
• Создать сущность для хранения настроек

У каждого из этих вариантов есть свои недостатки и положительные стороны.
На мой взгляд, наиболее удачный вариант — сущность с настройками логера, но в этом случае придется всякий раз вытаскивать эту сущность, так как кеширование настроек — не совсем удачное решение (плагин может долго исполняться, а я могу в этот момент поменять настройки).

Но в данном случае задача у меня больше ознакомительная, поэтому поехали дальше.

Напишем вот такой простенький плагинчик:

namespace LoggedPlugin
{
    public class TestPlugin:IPlugin
    {
        [Logging]
        private string SimpleMethod(string input)
        {
            return "Hello CRM";
        }

        [Logging]
        private void MethodThrowsException()
        {
            throw new NotImplementedException();
        }
        
        public void Execute(IServiceProvider serviceProvider)
        {
            SimpleMethod("Hi CRM");

            MethodThrowsException();
        }
    }
}

Аспект у нас будет иметь следующий код:

namespace LoggedPlugin.Logging
{
    [Serializable]
    public class LoggingAttribute : OnMethodBoundaryAspect
    {
        public override void OnException(MethodExecutionArgs args)
        {
            Logger.Instance.Error("Произошел сбой",args.Exception);
        }

        public override void OnEntry(MethodExecutionArgs args)
        {
            Logger.Instance.Trace(string.Format("{0}.{1}: Начат метод.", args.Method.DeclaringType.FullName, args.Method.Name));

            var argumentInfos = args.Method.GetParameters();

            for (var index = 0; index < args.Arguments.Count; index++)
            {
                var argument = args.Arguments[index];

                Logger.Instance.Trace(string.Format("{0}:{1}", argumentInfos[index].Name, argument));
            }
        }

        public override void OnSuccess(MethodExecutionArgs args)
        {
            Logger.Instance.Trace(string.Format("{0}.{1}: Завершен метод.", args.Method.DeclaringType.FullName, args.Method.Name));
        }
    }
}

Ну и собственно логер:

namespace LoggedPlugin.Logging
{
    public sealed class Logger
    {
        private static volatile Logger _instance;
        private static readonly object _syncRoot = new object();
        private readonly NLog.Logger _logger;

        private Logger()
        {
            var config = new LoggingConfiguration();

            var fileTarget = new FileTarget();

            config.AddTarget("file",fileTarget);

            fileTarget.FileName = @"C:\logs\log.txt";
            fileTarget.Layout = @"${date:format=[HH\:mm\:ss.fff]} ${level:uppercase=true} t[${threadid}] ${message} ${exception:format=ToString}";

            var loggingRule = new LoggingRule("*", LogLevel.Trace, fileTarget);

            config.LoggingRules.Add(loggingRule);

            LogManager.Configuration = config;

            _logger = LogManager.GetLogger("FileLogger");
        }

        public static Logger Instance
        {
            get
            {
                if (_instance == null)
                {
                    lock (_syncRoot)
                    {
                        if (_instance == null)
                            _instance = new Logger();
                    }
                }

                return _instance;
            }
        }

        public void Trace(string message)
        {
            _logger.Trace(message);
        }

        public void Error(string message, Exception e)
        {
            _logger.Error(message,e);
        }
    }
}

Логер такой с хардкодом, но большего и не надо — для академических целей!

Дальше мы подписываем сборку, билдим ее и мержим три сборки при помощи утилиты ILMerge:
LoggedPlugin.dll,NLog.dll и PostSharp.dll.

После чего публикуем результат в CRM:



Я повесил данный плагин на создание лида.

После создания лида, я увидел вот такой результат:

=========================================================
[22:46:51.816] TRACE t[31] LoggedPlugin.TestPlugin.SimpleMethod: Начат метод.
[22:46:51.863] TRACE t[31] input:Hi CRM
[22:46:51.863] TRACE t[31] LoggedPlugin.TestPlugin.SimpleMethod: Завершен метод.
[22:46:51.863] TRACE t[31] LoggedPlugin.TestPlugin.MethodThrowsException: Начат метод.
[22:46:51.863] ERROR t[31] Произошел сбой System.NotImplementedException: The method or operation is not implemented.
at LoggedPlugin.TestPlugin.MethodThrowsException()

=========================================================