Вот задеплоили мы своё приложение, и, как правильные и опытные разработчики, не забыли вставить в него крэш-репортер. Получаем первые репорты, открываем стек, смотрим на окружение, пробуем воспроизвести, обламываемся и задаём в пространство вопрос «
И тут нам здорово пригодились бы отладочные логи приложения, или хотя бы логи последних действий пользователя, что открывал, куда тыкал и т.п. Далее речь пойдет именно о логгировании действий пользователя в WinForms приложении и включении этого лога в крэшрепорт.
Первое что приходит в голову — наивный подход: вписать обработчики на каждое действие юзера и добавлять в лог запись. Но это куча работы и тупого кода. О’кей, может тогда сделаем базовую форму/контрол, где подпишемся на нужные события у всех, кто лежит внутри? Ой, а контролы оказывается умеют добавляться и удаляться, приложение leak-овать и всё это вместе ещё подтормаживать из-за нашего кода. А вот как бы нам написать всё то же самое, только без базовых форм, отслеживания изменений на форме, подписки на кучу событий, да ещё чтобы не тормозило?
Оказывается, всё уже придумано до нас — хуки! Но, позвольте, какой-же это WinForms, это же самый что ни на есть Win32 API?! А что делать,
Итак, нам интересно что пользователь делал, чтобы завалить приложение. То есть куда и как тыкал мышкой, какие клавиши нажимал, что вводил, какие окна открывал, как фокус двигал. Хватит для начала.
За мышку отвечают мышиные хуки, обычный и низкоуровневый. За клавиатуру, соответственно, клавиатурные, также обычный и низкоуровневый. Нам надо следить за вводом только в одном приложении, поэтому глобальные низкоуровневые хуки для нас, пожалуй, перебор.
Лирическое отступление
Зато низкоуровневые хуки самое то для специфических задачек, типа добавить управление мышкой в консольное приложение, которое про мышку ни слухом ни духом. Более того, не просто в консольное, а в DOS-овское. Когда-то давно, автор в бытность фидошником обучил Golded мышиному вводу именно при помощи низкоуровневого мышиного хука. Как потом оказалось, заработало и во многих других досовских программках.
А раз обычных хуков нам достаточно, то можно сразу на хук сообщений повеситься, там и мышка будет и клавиатура, в одном флаконе. Активацию окон и перемещение фокуса удобно ловить в CBT-хуке.
Куда копать понятно,
Поехали!
Описываем Interop-ы.
Подписываемся:
Для каждой нитки нужно ставить свой хук (см. threadId), поэтому заведём словарик
где
При подписке в словарик запись добавляем, при отписке убираем, все чин чинарём.
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 здесь, на Хабре.
Комментарии (12)
aquamakc
21.11.2017 16:51Антивирусы не паникуют при работе вашего логера? Периодически на тематических форумах вижу жалобы, что хукеры воспринимаются, как вирус.
mviorno Автор
21.11.2017 17:04Все возможные антивирусы не проверяли. Те что в наличии есть — не паникуют. По логике вещей и не должны бы, т.к. приложение установило хуки самостоятельно, при помощи кода из подписанной dll-ки, явно прописанной в зависимостях. Т.е. сборка вполне легально попала в процесс.
Более того, антивири не ругались даже в тех случаях, когда сборка в процесс внедрялась гораздо более противоестественным образом. Делал такое для техподдержки, для тех случаев, когда клиент по различным причинам не может или не хочет пересобирать/перевыкладывать приложение только ради включения в него крэш-репортера. А подробная информация о падении критично важна для воспроизведения и фикса.
MikePreyskurantov
21.11.2017 18:45+1Если проверять код сборки сканером по сигнатурам CWE, то можно получить примерно такое предупреждение: «В коде найдено использование хуков. Проверьте, что ничего противоправного этот код не делает». Не антивирус, конечно, но для полноты картины.
micb
21.11.2017 17:20По моему опыту, большая часть проблем возникает из-за данных, которые приложение обрабатывает. Чаще всего это данные получены из файла или из удаленного сервиса в сети, а не введены пользователем вручную. В этом случае, знание о том, куда пользователь ткнул и что нажал, мало поможет. Имхо лучше собирать логи и потом во время падения пытаться определить нужный набор логозаписей (т.е. относящихся к проблеме) и их уже отправлять?
Mirimon
21.11.2017 17:42Конечно же их мы тоже умеем собирать. Ситуации бывают разные и хорошо иметь всесторонний набор данных, нежели только что-то одно.
ferocactus
21.11.2017 19:02«Мы зачастую строим здания, которые склонны рушиться. Для решения этой проблемы увеличим скорость вращения Земли, чтобы вес объектов на её поверхности снизился...»
PsyHaSTe
24.11.2017 17:38Может стоило бы вместо словарика использовать `ThreadLocal`, который бы проследил сам, что айдишки потоков все правильные, да и использовать удобнее.
mviorno Автор
25.11.2017 01:24С использованием ThreadStatic/TLS проблематично сделать вот такую тотальную зачистку хуков:
protected void RemoveHooks() { lock (hooks) { foreach (int threadId in hooks.Keys) UninstallHook(threadId, hooks[threadId]); hooks.Clear(); } }PsyHaSTe
25.11.2017 01:58Почему нет?
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
С другой стороны, повторно повесить их уже не получится. Но ведь хуки логирования должны висеть всё время работы приложения, так что это не проблема, они никогда не удаляются.
adeptoleg
ИМХО Если уж беспокоится про приватность клиента там не столько пароли явно помеченные но и пароли с браузера будут попадать инфа о кредитках аккаунтах и другой всякой инфы. Да и сам по себе отчет слишком подробный по клавиатуре получается. Я думаю эффективней было бы собирать комбинации клавиш (горячих) и этого было бы вполне достаточно а набранный текст включать только с элемента где был последний раз фокус если он тестовый
mviorno Автор
Как раз сегодня запилили такую фичу в Web-клиенте — возможность исключить security-sensitive информацию из репорта ещё из до отправки его на сервер. См. файл, свойства IgnoreFormFields, IgnoreHeaders, IgnoreCookies, IgnoreServerVariables. Через запятую задаются маски имён ключей, которые на сервер отправлять не надо.
mviorno Автор
То что raw-отчёт по событиям слишком подробный — факт. Поэтому мы на сервере при показе его сильно «упрощаем» (см. по ссылке), а для мудрёных случаев сохранили возможность посмотреть исходный вариант. У меня про процесс упрощения в загашнике статья полуготовая лежит.