Стек: анализируем значения параметров

Очень часто, глядя на стек падения, хочется увидеть, а с какими значениями параметров были сделаны вызовы. Под отладчиком в VisualStudio мы эти значения посмотреть можем. А как быть в случае, если программа запущена без отладчика и обрабатывает исключения самостоятельно? За ответами добро пожаловать под кат.

Вопрос о значениях параметров для нас не праздный. Чуть ли не первый вопрос, который задают разработчики, когда пробуют наш крэш-репортер ^[1]: «А значения параметров посмотреть можно?»

Что-ж, поисследуем проблему поподробнее.

Вне зависимости от того, обработанное у нас исключение, или нет, изначально мы имеем сам объект Exception (и цепочку его InnerException-ов).

Стек падения добывается из свойства Exception.StackTrace ^[2], или можно его получить чуть в более подробном виде, создав объект типа System.Diagnostics.StackTrace ^[3]. И если по фреймам ^[4], содержащимся в StackTrace, можно определить, какие методы ^[5] вызывались, и какие у них сигнатуры ^[6], то значения параметров и ссылки на объекты (this) определить не получается.

Что же делать? Раз рантайм из коробки не отдаёт нужную нам информацию, попробуем собрать её самостоятельно.

Возьмём простейший код:

public void DoWork(string work) {
    DoInnerWork(work, 5);
}
public void DoInnerWork(string work, int times) {
    object o = null;
    o.ToString();
}

Завернём в содержимое методов try/catch. Каждое пойманное исключение зарегистрируем вместе со значениями параметров метода и отправим дальше:

public void DoWork(string work) {
    try {
        DoInnerWork(work, 5);
    }
    catch (Exception ex) {
        LogifyAlert.Instance.TrackArguments(ex, work);
        throw;
    }
}

public void DoInnerWork(string innerWork, this, int times) {
    try {
        object o = null;
        o.ToString();
    }
    catch (Exception ex) {
        LogifyAlert.Instance.TrackArguments(ex, this, innerWork, times);
        throw;
    }
}

Метод Track будет иметь сигнатуру:

public void TrackArguments(Exception ex, object instance, params object[] args)

и будет складывать себе во внутренний список или в словарь значения аргументов таким образом, чтобы их можно было привязать к соответствующим строчкам из Exception.StackTrace ^[2]. Также важно в правильные моменты очищать полученный список, в противном случае его содержимое станет неактуально уже для второго брошенного исключения. Какие это моменты? Вход в метод и успешный (без выброса исключения) выход из него, а также вход в глобальный обработчик исключений. Примерно вот так:

public void DoWork(string work) {
    LogifyAlert.Instance.ResetTrackArguments();
    try {
        DoInnerWork(work, 5);
        LogifyAlert.Instance.ResetTrackArguments();
    }
    catch (Exception ex) {
        LogifyAlert.Instance.TrackArguments(ex, work);
        throw;
    }
}
public void DoInnerWork(string innerWork, this, int times) {
    LogifyAlert.Instance.ResetTrackArguments();
    try {
        object o = null;
        o.ToString();
        LogifyAlert.Instance.ResetTrackArguments();
    }
    catch (Exception ex) {
        LogifyAlert.Instance.TrackArguments(ex, this, innerWork, times);
        throw;
    }
}

void MethodWithHandledException(string work) {
    LogifyAlert.Instance.ResetTrackArguments();
    try {
        DoInnerWork(work, 5);
        LogifyAlert.Instance.ResetTrackArguments();
    }
    catch (Exception ex) {
        HandleException(ex);
        LogifyAlert.Instance.ResetTrackArguments();
    }
}
void CurrentDomain_UnhandledException(object sender, UnhandledExceptionEventArgs e) {
    var map = LogifyAlert.Instance.MethodArgumentsMap;
    ExceptionTracker.Reset();
    // handle exception below
}

Выглядит феерично, код окончательно превратился в нечитаемое говно нечто. Первая реакция — снести и забыть, как страшный сон. Останавливает лишь то, что как ни крути, принцип неизменен, и значения параметров всё равно придётся собрать своими руками ^[7] (осторожно, 18+, много мата). Вопросы красоты кода обязательно будем решать, но только после того, как добьёмся работоспособности системы.

Как привязать значения параметров к строчкам стека? По порядковому номеру фрейма в стеке, вестимо! В тот момент, когда мы создаём System.Diagnostics.StackTrace ^[3], текущий фрейм всегда имеет индекс 0, а количество фреймов может быть разным. Когда исключение кидается впервые, кол-во фреймов (глубина стека) максимальна, во всех последующих rethrow этого же исключения глубина стека будет только меньше. Таким образом, номер строки в стеке (для конкретного исключения) есть разница между максимальной и текущей глубиной стека. В виде кода:

public void TrackArguments(Exception ex, MethodCallInfo call) {
    StackTrace trace = new StackTrace(0, false);
    int frameCount = trace.FrameCount;
    MethodCallStackArgumentMap map;
    if (!MethodArgumentsMap.TryGetValue(ex, out map)) {
        map = new MethodCallStackArgumentMap();
        map.FirstChanceFrameCount = frameCount;
        MethodArgumentsMap[ex] = map;
    }
    int lineIndex = map.FirstChanceFrameCount - frameCount;
    map[lineIndex] = call;
}

Где MethodCallInfo выглядит следующим образом:

public class MethodCallInfo {
    public object Instance { get; set; }
    public MethodBase Method { get; set; }
    public IList<object> Arguments { get; set; }
}

Привязку сделали. Запишем в крэш-репорт, отправим на сервер вместе с Exception.StackTrace ^[2], и там уже разберёмся с отображением. Получим что-то похожее на:

Принципиальная работоспособность подхода доказана, теперь надо сделать так, чтобы код не становился страшным, как ядерная война, а в идеале, чтобы вообще никакого кода писать не надо было бы.

Вспоминаем про такую полезную в хозяйстве вещь, как AOP ^[8].

Пробуем, например, Castle.DynamicProxy ^[9], создаём перехватчик:

public class MethodParamsInterceptor : IInterceptor {
    public void Intercept(IInvocation invocation) {
        try {
            LogifyAlert.Instance.ResetTrackArguments();
            invocation.Proceed();
            LogifyAlert.Instance.ResetTrackArguments();
        }
        catch (Exception ex) {
            LogifyAlert.Instance.TrackArguments(
                ex,
                CreateMethodCallInfo(invocation)
            );
            throw;
        }
    }
    MethodCallInfo CreateMethodCallInfo(IInvocation invocation) {
        MethodCallInfo result = new MethodCallInfo();
        result.Method = invocation.Method;
        result.Arguments = invocation.Arguments;
        result.Instance = invocation.Proxy;
        return result;
    }
}

Подключаем крэш-репортер:

var client = LogifyAlert.Instance;
client.ApiKey = "<my-api-key>";
client.StartExceptionsHandling();

Создаём тестовый класс с использованием перехватчика:

var proxy = generator.CreateClassProxy<ThrowTestExceptionHelper>(
    new MethodParamsInterceptor()
);
proxy.DoWork("work");

Выполняем и смотрим на результат:

Всё сработало хорошо, но есть целых несколько НО:

• Стек теперь очень захламлён фреймами от Castle.
• Перехват работает только с виртуальными методами и интерфейсами.
• Создание объектов стало довольно громоздким.

Последний пункт наиболее критичен – нам придётся значительно переписывать весть проект только ради значений параметров на стеке. Овчинка выделки едва ли стОит.

А может «есть такой же, но с перламутровыми пуговицами»? И таки есть, PostSharp ^[10]. Реализуем аспект:

[AttributeUsage(AttributeTargets.Method |
                AttributeTargets.Class |
                AttributeTargets.Assembly |
                AttributeTargets.Module)]
[Serializable]
public class CollectParamsAttribute : OnMethodBoundaryAspect {
    public override bool CompileTimeValidate(MethodBase method) {
        if (method.GetCustomAttribute(typeof(IgnoreCallTrackingAttribute)) != null ||
            method.Name == "Dispose") {
            return false;
        }
        return base.CompileTimeValidate(method);
    }

    public override void OnEntry(MethodExecutionArgs args) {
        base.OnEntry(args);
        LogifyAlert.Instance.ResetTrackArguments();
    }
    public override void OnSuccess(MethodExecutionArgs args) {
        LogifyAlert.Instance.ResetTrackArguments();
        base.OnSuccess(args);
    }
    [MethodImpl(MethodImplOptions.NoInlining)]
    public override void OnException(MethodExecutionArgs args) {
        if (args.Exception == null)
            return;

        if (args.Method != null && args.Arguments != null && args.Instance != this)
            LogifyAlert.Instance.TrackArguments(args.Exception,
                                                CreateMethodCallInfo(args));

        base.OnException(args);
    }
    MethodCallInfo CreateMethodCallInfo(MethodExecutionArgs args) {
        MethodCallInfo result = new MethodCallInfo();
        result.Method = args.Method;
        result.Arguments = args.Arguments;
        result.Instance = args.Instance;
        return result;
    }
}

В коде есть несколько ньюансов. Первое: запрещаем PostSharp-у инструментировать методы, помеченные атрибутом IgnoreCallTrackingAttribute. Ради чего? Вспоминаем вот этот код:

void CurrentDomain_UnhandledException(object sender, UnhandledExceptionEventArgs e) {
    var map = LogifyAlert.Instance.MethodArgumentsMap;
    ExceptionTracker.Reset();
    // handle exception below
}

Что произойдет при его вызове, если PostSharp его перепишет? Вызовется метод OnEntry аспекта, который первым делом зачистит с таким трудом собранные нами параметры вызовов. Epic Fail. Поэтому все методы, где нам необходимо обращаться к MethodCallArgumentsTracker следует пометить атрибутом IgnoreCallTrackingAttribute.

Второе: запрещаем переписывать Dispose. Казалось бы, причём здесь Лужков зачем? А затем, что летит у нас исключение из глубин приложения, а по пути вовсю выполняются блоки catch, finally и прочий код, теряются ссылки на локальные объекты, GC начинает их зачищать. В общем, вероятность выполнения Dispose в этот период довольно велика, а чтобы угробить содержимое LogifyAlert.Instance.MethodArgumentsMap «достаточно одной таблэтки».

Третий ньюанс в странной проверке:

if (args.Method != null && args.Arguments != null && args.Instance != this)
    LogifyAlert.Instance.TrackArguments(
        args.Exception,
        CreateMethodCallInfo(args)
    );

Дело в том, что PostSharp агрессивно оптимизирует код, который встраивает в методы. И если мы явно не обратимся к полям MethodExecutionArgs, то получим в значениях этих полей вполне кошерный null, что, разумеется, сделает нам всю дальнейшую логику бессмысленной.

Итак, лёгким движением руки применяем аспект на всю сборку:

[assembly: CollectParams]

Выполняем и смотрим крэш-репорт:

Стек выглядит как новенький как старенький, ничего лишнего. Изменения же в существующем коде минимальны. Результат, близкий к идеальному! Из потенциальных минусов — использование PostSharp, как такового, в процессе сборки. Возможно, это кого-нибудь оттолкнёт.

Какие ещё есть возможные варианты, кроме PostSharp и ему подобных?

В первую очередь, это написание profiler-а и использование методов ICorProfilerInfo::GetILFunctionBody ^[11] и ICorProfilerInfo::SetILFunctionBody ^[12] для того, чтобы модифицировать тела методов прямо во время выполнения программы. Хорошую серию статей о том, как это делать, можно почитать здесь ^[13]. Неплохая подборка ссылок по теме тут ^[14].

Плюсы

• используются штатные возможности CLR;
• не потребуется вообще никакая модификация исходного кода;
• всё будет работать в рантайме.

Минусы

• будет работать в рантайме, а значит чуток притормаживать программу.
• профилировщик не может быть написан ^[15] в managed коде.
• сборку профилировщика необходимо зарегистрировать в системе
• перед запуском приложения, надо правильно настроить окружение ^[16].

Ещё остаются хакерские методы, только хардкор, достойный Чака Норриса ^[17], который, как известно:

Вот тут ^[18] описан подход, заключающийся в том, что если удастся правильно определить адреса некоторых непубличных функций реализации JIT-а, то можно попробовать аккуратно воспользоваться ими для подмены IL-кода методов непосредственно перед компиляцией их в нативный код. Недостатки в том, что правильно определить адреса функций непросто, и что они могут регулярно меняться вместе с обновлениями. Так, пример из статьи у автора просто не заработал, т.к. нужные адреса определить не удалось. Ещё минус — подход не заработает, если сборку обработали NGen-ом ^[19].

Ещё одно шикарное описание ^[20] оригинального способа перехвата методов было опубликовано камрадом ForwardAA ^[21], здесь, на хабре. Вполне возможно, что при должной доработке напильником его подход может быть адаптирован и для задачи сбора значений аргументов вызовов. Из плюсов — вполне вероятно, что подход будет работоспособен даже после обработки сборки NGen-ом ^[19].

Вывод

Самый надёжный на текущий момент способ собрать значения аргументов вызовов в момент возникновения исключения — использование Postsharp. Собранные значения клиент Logify ^[1] умеет привязать к стеку, записанному при возникновении исключения. Полученный крэш-репорт за счёт этого в отдельных случаях может оказаться значительно более информативным, нежели содержащий только стек.

Автор: LenaD

Источник ^[22]