Оно само упало, или следствие ведут колобки


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

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

    Первое что приходит в голову — наивный подход: вписать обработчики на каждое действие юзера и добавлять в лог запись. Но это куча работы и тупого кода. О’кей, может тогда сделаем базовую форму/контрол, где подпишемся на нужные события у всех, кто лежит внутри? Ой, а контролы оказывается умеют добавляться и удаляться, приложение leak-овать и всё это вместе ещё подтормаживать из-за нашего кода. А вот как бы нам написать всё то же самое, только без базовых форм, отслеживания изменений на форме, подписки на кучу событий, да ещё чтобы не тормозило?

    Оказывается, всё уже придумано до нас — хуки! Но, позвольте, какой-же это WinForms, это же самый что ни на есть Win32 API?! А что делать, жить захочешь — не так раскорячишься вам шашечки, или ехать?

    Итак, нам интересно что пользователь делал, чтобы завалить приложение. То есть куда и как тыкал мышкой, какие клавиши нажимал, что вводил, какие окна открывал, как фокус двигал. Хватит для начала.

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

    Лирическое отступление
    Зато низкоуровневые хуки самое то для специфических задачек, типа добавить управление мышкой в консольное приложение, которое про мышку ни слухом ни духом. Более того, не просто в консольное, а в DOS-овское. Когда-то давно, автор в бытность фидошником обучил Golded мышиному вводу именно при помощи низкоуровневого мышиного хука. Как потом оказалось, заработало и во многих других досовских программках.

    А раз обычных хуков нам достаточно, то можно сразу на хук сообщений повеситься, там и мышка будет и клавиатура, в одном флаконе. Активацию окон и перемещение фокуса удобно ловить в CBT-хуке.

    Куда копать понятно,

    Поехали!
    Описываем Interop-ы.

    delegate int HookProc(int ncode, IntPtr wParam, IntPtr lParam);
    [DllImport("kernel32.dll", ExactSpelling = true, CharSet = CharSet.Auto)]
    static extern int GetCurrentThreadId ();
    [DllImport("USER32.dll", CharSet = CharSet.Auto)]
    static extern IntPtr SetWindowsHookEx(int idHook, HookProc lpfn, IntPtr hMod, int dwThreadId);
    [DllImport("USER32.dll", CharSet = CharSet.Auto)]
    static extern int CallNextHookEx(IntPtr hhk, int nCode, IntPtr wParam, IntPtr lParam);
    [DllImport("USER32.dll", CharSet = CharSet.Auto)]
    static extern bool UnhookWindowsHookEx(IntPtr hhk);

    Подписываемся:

    const int WH_GETMESSAGE = 3;
    const int WH_CBT = 5;
    IntPtr getMsgHookHandle = SetWindowsHookEx(WH_GETMESSAGE, GetMsgProc, IntPtr.Zero, threadId);
    IntPtr cbtHookHandle = SetWindowsHookEx(WH_CBT, CbtProc, IntPtr.Zero, threadId)
    static int GetMsgProc(int nCode, IntPtr wParam, IntPtr lParam) {
        return CallNextHookEx(IntPtr.Zero, nCode, wParam, lParam);
    }
    static int CbtProc(int nCode, IntPtr wParam, IntPtr lParam) {
        return CallNextHookEx(IntPtr.Zero, nCode, wParam, lParam);
    }
    

    Для каждой нитки нужно ставить свой хук (см. threadId), поэтому заведём словарик

    static readonly Dictionary<int, HookInfo> hooks = new Dictionary<int, HookInfo>();

    где

    class HookInfo {
        internal IntPtr GetMsgHookHandle;
        internal IntPtr CbtHookHandle;
        internal bool InHook;
    }

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

    Хренак, хренак, и в продакшен! Ага, щаззз, это .NET, детка. Валится, если не сразу, то после 1-2 подписок/отписок на хуки, прямо на вызове CallNextHookEx. Интуитивно ясно, что имеем dangling pointer, но при беглом взгляде на код непонятно, а с чего бы? Помотрим внимательно на SetWindowsHookEx. Вторым параметром идёт указатель на функцию-обработчик. То есть адрес обработчика, в терминах C# это будет IntPtr. Тааак, а если заменить HookProc lpfn на IntPtr lpfn? Тогда придется использовать Marshal. GetFunctionPointerForDelegate для получения адреса из делегата. Смотрим на изначальный код — в явном виде делегат мы не создаем. Смотрим при помощи ilspy:

    SetWindowsHookEx(3, new HookProc(Win32HookManagerBase.GetMsgProc), IntPtr.Zero, threadId);

    Так вот ты какой, северный олень! Спасибо тебе, синтаксический сахар, ты спрятал от нас важную вещь — создаётся промежуточный объект делегата, содержащий в себе адрес, который успешно передаётся в unmanaged-код. После чего объект делегата успешно прибивается сборщиком мусора и unmanaged код начинает валиться при попытке передать управление в никуда.

    Ок, явным образом сохраняем делегаты:

    static HookProc procGetMsg = Win32HookManager.GetMsgProc;
    static HookProc procCbt = Win32HookManager.CbtProc;
    
    SetWindowsHookEx(WH_GETMESSAGE, procGetMsg, IntPtr.Zero, threadId);
    SetWindowsHookEx(WH_CBT, procCbt, IntPtr.Zero, threadId);

    Компилим, проверяем — работает.

    Полдела сделали, уведомления о событиях научились получать. Теперь надо собрать и записать информацию, которая позволит нам показывать события в понятном и удобочитаемом для человека виде.

    Возьмём, например

    Мышиные сообщения
    Win32.WindowsMessages message = (Win32.WindowsMessages)m.Msg;
    if (message == Win32.WindowsMessages.WM_LBUTTONUP)
        ProcessMouseMessage(ref m, MouseButtons.Left, true);
    else if (message == Win32.WindowsMessages.WM_RBUTTONUP)
        ProcessMouseMessage(ref m, MouseButtons.Right, true);
    else if (message == Win32.WindowsMessages.WM_MBUTTONUP)
        ProcessMouseMessage(ref m, MouseButtons.Middle, true);
    else if (message == Win32.WindowsMessages.WM_LBUTTONDOWN)
        ProcessMouseMessage(ref m, MouseButtons.Left, false);
    else if (message == Win32.WindowsMessages.WM_RBUTTONDOWN)
        ProcessMouseMessage(ref m, MouseButtons.Right, false);
    else if (message == Win32.WindowsMessages.WM_MBUTTONDOWN)
        ProcessMouseMessage(ref m, MouseButtons.Middle, false);
    
    void ProcessMouseMessage(ref Message m, MouseButtons button, bool isUp) {
        Dictionary<string, string> data = new Dictionary<string, string>();
        data["mouseButton"] = button.ToString();
        data["action"] = isUp ? "up" : "down";
    
        Breadcrumb item = new Breadcrumb();
        item.Event = isUp ? BreadcrumbEvent.MouseUp : BreadcrumbEvent.MouseDown;
        item.CustomData = data;
        AddBreadcrumb(item);
    }


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



    
    static void Main() {
        LogifyAlert client = LogifyAlert.Instance;
        client.ApiKey = "<my-api-key>";
        client.CollectBreadcrumbs = true;
        client.StartExceptionsHandling();
        // etc
    }
    void showMessageButton_Click(object sender, EventArgs e) {
        MessageBox.Show(this, "text");
    }
    void crashMeButton_ClickEvent(object sender, EventArgs e) {
        object o = null;
        o.ToString();
    }
    

    На серверной стороне формируем описания действий пользователя на основе собранной информации, примерно вот так:

    string GenerateMouseEventMessage(Breadcrumb breadcrumb) {
        return
            GetBreadcrumbCustomField(breadcrumb, "mouseButton") +
            " mouse button" +
            GetBreadcrumbCustomField(breadcrumb, "action");
    }
    

    Открываем и смотрим на присланные записи.



    Понятно, что ничего непонятно. Да, пользователь тыкал мышкой, но куда именно? А это мы не записали и не прислали. Что у нас там интересного в мышиных сообщениях есть? О, hWnd, то что надо.

    [DllImport("user32.dll")]
    static extern int GetWindowText(IntPtr hWnd, StringBuilder lpString, int nMaxCount);
    
    string GetWindowText(ref Message m) {
        StringBuilder windowText = new StringBuilder(1024);
        GetWindowText(m.Hwnd, windowText, 1024);
        return windowText.ToString();
    }
    

    Заодно уж впишем в лог, какие клавиши нажимал пользователь.

    Клиент
    if (message == Win32.WindowsMessages.WM_KEYDOWN)
        ProcessKeyMessage(ref m, false);
    else if (message == Win32.WindowsMessages.WM_KEYUP)
        ProcessKeyMessage(ref m, true);
    else if (message == Win32.WindowsMessages.WM_CHAR)
        ProcessKeyCharMessage(ref m);
    
    void ProcessKeyMessage(ref Message m, bool isUp) {
        Dictionary<string, string> data = new Dictionary<string, string>();
        data["key"] = ((Keys)m.WParam).ToString();
        data["action"] = isUp ? "up" : "down";
        data["windowCaption"] = GetWindowText(ref m);
    
        Breadcrumb item = new Breadcrumb();
        item.Event = isUp ? BreadcrumbEvent.KeyUp : BreadcrumbEvent.KeyDown;
        item.CustomData = data;
        AddBreadcrumb(item);
    }
    void ProcessKeyCharMessage(ref Message m) {
        Dictionary<string, string> data = new Dictionary<string, string>();
        data["char"] = new string((char)m.WParam, 1);
        data["action"] = "press";
        data["windowCaption"] = GetWindowText(ref m);
    
        Breadcrumb item = new Breadcrumb();
        item.Event = BreadcrumbEvent.KeyPress;
        item.CustomData = data;
    
        AddBreadcrumb(item);
    }
    


    Сервер
    string GenerateMouseEventMessage(Breadcrumb breadcrumb) {
        return
            GetBreadcrumbCustomField(breadcrumb, "mouseButton") +
            " mouse button" +
            GetBreadcrumbCustomField(breadcrumb, "action") +
            " over " +
            GetBreadcrumbCustomField(breadcrumb, "windowCaption");
    }
    string GenerateKeyEventMessage(Breadcrumb breadcrumb) {
        return
            GetBreadcrumbCustomField(breadcrumb, "key") +
            GetBreadcrumbCustomField(breadcrumb, "action");
    }
    string GenerateKeyCharEventMessage(Breadcrumb breadcrumb) {
        string character = GetBreadcrumbCustomField(breadcrumb, "char");
        if (!String.IsNullOrEmpty(character))
            return "Type " + character;
        else
            return GetBreadcrumbCustomField(breadcrumb, "key") + " press";
    }


    Пересобираем, запускаем, генерируем и смотрим новый крэшрепорт.



    Уже неплохо. И нажатия клавиш адекватно показались, можно начинать пароли собирать. Кстати о птичках, пароли. Наверное, нехорошо отправлять приватную информацию без явного на то согласия пользователя. Пожалуй,

    Заменим звёздочками
    bool ProcessKeyMessage(ref Message m, bool isUp) {
        string key = ((Keys)m.WParam).ToString();
        bool maskKey = IsPasswordBox(ref m);
        if (maskKey)
            key = Keys.Multiply.ToString();
    
        Dictionary<string, string> data = new Dictionary<string, string>();
        data["key"] = key;
        // etc
    }
    
    bool ProcessKeyCharMessage(ref Message m) {
        char @char = (char)m.WParam;
        bool maskKey = IsPasswordBox(ref m);
        if (maskKey)
            @char = '*';
    
        Dictionary<string, string> data = new Dictionary<string, string>();
        data["char"] = new string(@char, 1);
        // etc
    }
    


    Теперь надо реализовать метод IsPasswordBox, и станет совсем хорошо. Чем же отличается обычное поле ввода, от поля ввода паролей? Вновь вызываем из глубин памяти воспоминания о WinAPI, находим вот такой примерчик. Из него видим, что нам нужен edit control со стилем ES_PASSWORD, у которого выставлен ненулевой password char. Реализуем:

    
    [DllImport("USER32.dll")]
    static extern int GetWindowLong(IntPtr hwnd, int flags);
    [DllImport("USER32.dll")]
    static extern int SendMessage(IntPtr hWnd, int Msg, IntPtr wParam, IntPtr lParam);
    
    static bool IsPasswordBox(IntPtr hWnd) {
        const int ES_PASSWORD = 32;
        int style = GetWindowLong(hWnd, GWL_STYLE);
        if ((style & ES_PASSWORD) == 0)
            return false;
    
        int result = SendMessage(hWnd, EM_GETPASSWORDCHAR, IntPtr.Zero, IntPtr.Zero);
        return result != 0;
    }

    Получаем:



    С кнопочками и полями ввода все хорошо работает. А если усложнить задачку? Встроимся в демо-приложение со сложными контролами, гридом и риббоном.



    Запустим, потыкаем в грид и кнопки на риббоне, посмотрим на результат:



    Печальное зрелище. На весь риббон у нас один единственный hWnd, а на грид аж целых два, один на сам грид, а другой на активный редактор. И что же нам со всем этим добром делать? Копаться в потрохах конкретных контролов не вариант — их слишком много и от разных вендоров, да и внутренности могут вполне себе регулярно меняться. Вспоминаем про Section 508, и начинаем выяснять, что это такое и с чем его едят. В результате узнаем про IAccessible а через некоторое время и про методы AccessibleObjectFromWindow и AccessibleObjectFromPoint. Первый метод как раз подойдет для клавиатурных событий, а второй для мышиных.

    Ещё чуток кода
    [return: MarshalAs(UnmanagedType.Bool)]
    static extern bool ClientToScreen(IntPtr hwnd, ref POINT point);
    [DllImport("oleacc.dll")]
    static extern IntPtr AccessibleObjectFromPoint(POINT pt, [Out, MarshalAs(UnmanagedType.Interface)] out IAccessible accObj, [Out] out object ChildID);
    [DllImport("oleacc.dll")]
    static extern int AccessibleObjectFromWindow(IntPtr hwnd, int id, ref Guid iid, [In, Out, MarshalAs(UnmanagedType.IUnknown)] ref object ppvObject);
    
    static IAccessible GetAccessibleObject(IntPtr hWnd) {
        Guid guid = new Guid("618736e0-3c3d-11cf-810c-00aa00389b71");
        Object instance = null;
        const int OBJID_WINDOW = 0x0;
        int hResult = AccessibleObjectFromWindow(hWnd, OBJID_WINDOW, ref guid, ref instance);
        if (hResult != 0 || instance == null)
            return null;
        return instance as IAccessible;
    }
    static IAccessible GetAccessibleObject(IntPtr hWnd, Point point) {
        IAccessible accObj;
        object obj = new object();
        POINT pt = new POINT();
        pt.X = point.X;
        pt.Y = point.Y;
        ClientToScreen(hWnd, ref pt);
        if (AccessibleObjectFromPoint(pt, out accObj, out obj) != IntPtr.Zero)
            return null;
        if (accObj == null)
            return null;
        return accObj;
    }
    


    Дальше уже дело техники. Если получили ненулевой IAccessible, то анализируем AccessibleRole, и записываем accName контрола и его родителя, если это надо.

    И опять лирика
    Есть ещё как минимум один способ выяснить, во что ткнул мышкой пользователь. Точнее даже так: в какой текст ткнул пользователь. Но способ настолько нетрадиционен, что автор воздержится от его использования, дабы не быть заслуженно обвинённым в перректальной тонзиллэктомии. Суть метода в следующем. Учимся перехватывать WinAPI функции отрисовки текста, например так. Далее, когда нам надо выяснить текст под мышкой, включаем перехват и начинаем записывать в отдельный блокнотик, какой текст и где рисовался. Затем заставляем окно под мышкой перерисоваться и выключаем перехват. Потом спокойно читаем блокнотик и определяем текст, который нарисовался непосредственно под мышкой. По косвенным данным (да и не только по косвенным), именно так работает фича Quick Lookup у ребят из команды Abbyy Lingvo.

    Далее допиливаем серверную часть и получаем уже вот такую картину:



    Стало гораздо информативнее, вполне понятно к какому контролу (или к какой его части) относится каждая запись. Работать уже можно, но теперь уже захотелось увидеть те же самые действия пользователя, но в еще более компактном виде. Чем далее и займёмся.

    PS:

    Исходники WinForms клиента

    Если кому интересно, сайт проекта и документация.
    Также вводная статья про Logify здесь, на Хабре.
    Сбор активности пользователя под другими платформами: WPF, JavaScript, ASP.NET
    DevExpress 370,97
    Компания
    Поделиться публикацией
    Комментарии 13
    • +1
      ИМХО Если уж беспокоится про приватность клиента там не столько пароли явно помеченные но и пароли с браузера будут попадать инфа о кредитках аккаунтах и другой всякой инфы. Да и сам по себе отчет слишком подробный по клавиатуре получается. Я думаю эффективней было бы собирать комбинации клавиш (горячих) и этого было бы вполне достаточно а набранный текст включать только с элемента где был последний раз фокус если он тестовый
      • 0
        Как раз сегодня запилили такую фичу в Web-клиенте — возможность исключить security-sensitive информацию из репорта ещё из до отправки его на сервер. См. файл, свойства IgnoreFormFields, IgnoreHeaders, IgnoreCookies, IgnoreServerVariables. Через запятую задаются маски имён ключей, которые на сервер отправлять не надо.
        • 0
          То что raw-отчёт по событиям слишком подробный — факт. Поэтому мы на сервере при показе его сильно «упрощаем» (см. по ссылке), а для мудрёных случаев сохранили возможность посмотреть исходный вариант. У меня про процесс упрощения в загашнике статья полуготовая лежит.
        • +2
          Антивирусы не паникуют при работе вашего логера? Периодически на тематических форумах вижу жалобы, что хукеры воспринимаются, как вирус.
          • 0
            Все возможные антивирусы не проверяли. Те что в наличии есть — не паникуют. По логике вещей и не должны бы, т.к. приложение установило хуки самостоятельно, при помощи кода из подписанной dll-ки, явно прописанной в зависимостях. Т.е. сборка вполне легально попала в процесс.

            Более того, антивири не ругались даже в тех случаях, когда сборка в процесс внедрялась гораздо более противоестественным образом. Делал такое для техподдержки, для тех случаев, когда клиент по различным причинам не может или не хочет пересобирать/перевыкладывать приложение только ради включения в него крэш-репортера. А подробная информация о падении критично важна для воспроизведения и фикса.
            • +1
              Если проверять код сборки сканером по сигнатурам CWE, то можно получить примерно такое предупреждение: «В коде найдено использование хуков. Проверьте, что ничего противоправного этот код не делает». Не антивирус, конечно, но для полноты картины.
            • 0
              По моему опыту, большая часть проблем возникает из-за данных, которые приложение обрабатывает. Чаще всего это данные получены из файла или из удаленного сервиса в сети, а не введены пользователем вручную. В этом случае, знание о том, куда пользователь ткнул и что нажал, мало поможет. Имхо лучше собирать логи и потом во время падения пытаться определить нужный набор логозаписей (т.е. относящихся к проблеме) и их уже отправлять?
              • 0
                Конечно же их мы тоже умеем собирать. Ситуации бывают разные и хорошо иметь всесторонний набор данных, нежели только что-то одно.
              • +5
                «Мы зачастую строим здания, которые склонны рушиться. Для решения этой проблемы увеличим скорость вращения Земли, чтобы вес объектов на её поверхности снизился...»
                • +1
                  Может стоило бы вместо словарика использовать `ThreadLocal`, который бы проследил сам, что айдишки потоков все правильные, да и использовать удобнее.
                  • 0
                    С использованием ThreadStatic/TLS проблематично сделать вот такую тотальную зачистку хуков:

                    protected void RemoveHooks() {
                        lock (hooks) {
                            foreach (int threadId in hooks.Keys)
                                UninstallHook(threadId, hooks[threadId]);
                            hooks.Clear();
                        }
                    }
                    
                    • +1

                      Почему нет?


                      protected void RemoveHooks() {
                          lock (hooks) {
                              foreach (var hook in hooks.Values)
                                  UninstallHook(hook);
                          }
                      }

                      https://msdn.microsoft.com/en-us/library/hh194898(v=vs.110).aspx


                      С другой стороны, повторно повесить их уже не получится. Но ведь хуки логирования должны висеть всё время работы приложения, так что это не проблема, они никогда не удаляются.

                      • 0
                        Интересная штука, не знал. В нашем конкретном случае всё равно её не получилось бы использовать — нужна поддержка .net framework 4.0

                  Только полноправные пользователи могут оставлять комментарии. Войдите, пожалуйста.

                  Самое читаемое