DZis is a Test: C#: Как добавить автоматическое логирование вызова метода при помощи Castle DynamicProxy и Humanizer

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

Добавить «человеческое» логирование можно несколькими способами. Я предлагаю, сделать это просто называя шаги «человеческими» именами. С одной стороны, это улучшит читабельность кода, с другой стороны – не требует дополнительных временных затрат на добавление логирования в процессе разработки тестов.

Давайте вначале рассмотрим следующую организацию тестовых шагов. В данном примере у нас есть класс Animal, который содержит некоторый базовый функционал, наследуемый дочерними классами. В данном примере, это метод «HappyBirthday()».

Такие методы мы будем называть «тестовыми шагами».

Допустим, в нашем приложении есть некоторая сущность – Cow. У коровы есть только один тестовый шаг: SayMoo().

И еще одна сущность – Tester, с единственным тестовым шагом – Assert_that_each_tester_should_read_DZis_is_a_test_Blog().

И тут я хотел бы пояснить, что пример с животными я взял намерено для того, чтобы не усложнять код и не привязываться к конкретному тестовому фреймворку. Но, внутри таких тестовых шагов могут скрываться и вызовы функций базы данных, и клики на Selenium, WatiN, White, CodedUI. Но, в этом примере, тестовые шаги просто выводят текст на экран.

И еще пояснение. Cow и Tester – это роли в нашем приложении. Например, если вы автоматизируете интернет магазин, то у вас были бы роли Customer, Administrator, Product, KorZina ;)

Роли – это классы, содержащие специфичные для них тестовые шаги (методы).

В данном примере, роли выглядят так:

public abstract class Animal
{
    public void HappyBirthday()
    {
        Console.WriteLine("\tNew Animal was Created");
    }
}

public class Cow : Animal
{
    public void SayMoo()
    {
        Console.WriteLine("\tCow: Mooooo!");
    }
}

public class Tester : Animal
{
    public void Assert_that_each_tester_should_read_DZis_is_a_test_Blog()
    {
        Console.WriteLine("\tTester: That's true! That's true!: http://blog.zhariy.com");
    }
}

А пример тест-кейса следующий:

static void Main(string[] args)
{
    var cow = new Cow();
    cow.HappyBirthday();
    cow.SayMoo();

    var tester = new Tester();
    tester.HappyBirthday();
    tester.Assert_that_each_tester_should_read_DZis_is_a_test_Blog();
}

Код на Github Gist

Steps – точка входа!

Перед тем как перейти к разбору логирования, давайте еще немного потерпим, и сделаем существующий код немного более легким для чтения.

Вот, например, есть строка, которая создает новый объект коровы:
var cow = new Cow();

Как вы думаете, она нужна в нашем тесте? Я думаю – нет. Все эти конструкторы, new… они только отвлекают при чтении кода. Это синтаксический шум.
Давайте воспользуемся тем паттерном, который программисты называют «Фабричным методом», а я называю «Точкой Входа».

А выглядит это даже проще, чем описано выше:

public static class Steps
{
    public static Cow Cow { get { return new Cow() } }
    public static Tester Tester { get { return new Tester(); } }
}

static void Main(string[] args)
{
    Steps.Cow.HappyBirthday();
    Steps.Cow.SayMoo();

    var tester = Steps.Tester;
    tester.HappyBirthday();
    tester.Assert_that_each_tester_should_read_DZis_is_a_test_Blog();
}

Как видите, у нас появился класс Steps, который служит точкой входа в нужный нам класс. В данном примере, просто прячет в своих недрах создание нового объекта.

Теперь, если хотите, можно вызывать методы без использования переменной с экземпляром объекта:
Steps.Cow.HappyBirthday();

А можно и использовать переменную. Точка входа нас ничем не ограничивает.
var tester = Steps.Tester;
tester.HappyBirthday();

Код на Github Gist

Самый простой способ добавить логирование

Тут ничего нового. Этим способом пользуются в 99% случаев.
Давайте явно добавим строки логирования в каждый метод.

Например, если раньше шаг SayMoo() выглядел так:

public void SayMoo()
{
    Console.WriteLine("\tCow: Mooooo!");
}

То после добавления строк логирования, получится следующее:

public void SayMoo()
{
    Console.WriteLine(@"Started Step: SayMoo");

    Console.WriteLine("\tCow: Mooooo!");

    Console.WriteLine(@"Finished Step: SayMoo");
}

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

Код на Github Gist

Логирование посредством прокси класса

Давайте рассмотрим код SayMoo() еще раз, и постараемся определить лишние строки кода:

public void SayMoo()
{
    Console.WriteLine(@"Started Step: SayMoo");

    Console.WriteLine("\tCow: Mooooo!");

    Console.WriteLine(@"Finished Step: SayMoo");
}

Как не странно, но только что добавленные строки Started Step: / Finished Step: я и считаю лишними. Посудите сами, имя шага у нас уже есть. И оно хранится в самом имени метода SayMoo(). Так почему бы нам динамически не перехватить ситуацию, когда метод вызывается и когда завершается?
И такое средство есть. И использовать его не сложно.

Castle.DynamicProxy (из Castle.Core) позволяет создать магически-динамический класс, который позволит перехватывать вызовы методов из классов Cow и Tester. При этом, Cow и Tester и догадываться не будут, что их так нагло перехватывают.

Для того чтобы все заработало, необходимо добавить два класса:
MyProxy<TClass> – универсальный класс, служащий для инициализации динамического прокси объекта на базе наших Cow, Tester или любого другого класса с шагами.

ClassInterceptor – содержит единственный метод – Intercept, который и будет реализовывать перехват и логирование.

Humanizer – содержит единственный метод-расширение Humanize(). Он позволяет преобразовать следующий текст имени метода: “CamelCaseMethodName” в “Camel case method name”, и точно также хорошо заменяет “Underscore_method_name” на “Underscore method name”.

Для того чтобы магия заработала, необходимо добавить следующие два класса. Еще раз подчеркну, что этот код будет универсально работать не только для существующих классов Cow и Tester, но и для любых других классов, которые мы захотим добавить в будущем.

public class MyProxy<TClass> where TClass : class
{
    private TClass _object;
    public TClass Object
    {
        get { return _object ?? (_object = CreateNewClass()); }
    }

    private static readonly ProxyGenerator ProxyGenerator = new ProxyGenerator();

    private TClass CreateNewClass()
    {
        return ProxyGenerator.CreateClassProxy<TClass>(new ClassInterceptor());
    }
}

public class ClassInterceptor : IInterceptor
{
    public void Intercept(IInvocation invocation)
    {
        string readableMethodName = invocation.Method.Name.Humanize();

        Console.ForegroundColor = ConsoleColor.Green;
        Console.Write("[Started]  ");
        Console.ResetColor();

        Console.WriteLine("Step: " + readableMethodName);

        invocation.Proceed();

        Console.ForegroundColor = ConsoleColor.Yellow;
        Console.Write("[Finished] ");
        Console.ResetColor();
        Console.WriteLine("Step: " + readableMethodName);

        Console.ForegroundColor = ConsoleColor.Magenta;
        Console.WriteLine(new String('~', 40));
        Console.ResetColor();
    }
}

Теперь давайте почистим наши тестовые шаги от лишнего логирования. При этом, чтобы перехваты работали, в данной реализации, очень важно обозначить все методы, которые мы хотим перехватывать при помощи модификатора virtual. Невиртуальные методы перехватываться не будут.
Так что наш SayMoo():

public void SayMoo()
{
    Console.WriteLine(@"Started Step: SayMoo");

    Console.WriteLine("\tCow: Mooooo!");

    Console.WriteLine(@"Finished Step: SayMoo");
}

Превращается в:

public virtual void SayMoo()
{
    Console.WriteLine("\tCow: Mooooo!");
    throw new Exception("Cannot say mooo :(");
}

Ну, и последнее усложнение. Нам необходимо изменить Точку входа – класс Steps.
Из предыдущей реализации:

public static class Steps
{
    public static Cow Cow { get { return new Cow(); } }
    public static Tester Tester { get { return new Tester(); } }
}

Превращается в следующую:

public static class Steps
{
    public static Cow Cow { get { return new MyProxy<Cow>().Object; } }
    public static Tester Tester { get { return new MyProxy<Tester>().Object; } }
}

И это всё! Тестовой код (благодаря Точке входа) менять необходимости нет.

Пример лога с ошибкой:

Лог без ошибок:

Финальный исходный код:
Код на Github Gist

DZis is a Test

воскресенье, февраля 24, 2013

C#: Как добавить автоматическое логирование вызова метода при помощи Castle DynamicProxy и Humanizer

Steps – точка входа!

Самый простой способ добавить логирование

Логирование посредством прокси класса

Полезные материалы

Комментариев нет: