![[personal profile]](https://www.dreamwidth.org/img/silk/identity/user.png){kind=small}
metaclass"Сначала мы себе создаем проблемы, а потом их героически решаем."
Проявился, значит, в одном из сервисов, призванных работать 24/7, странный баг.
Все работает, никаких исключений, никаких признаков ничего плохого - но данные в базу не попадают. Появляется ну раз в месяц, может быть. Бесил, ибо был необъясним.
Добавил в сервис консоль удаленного управления, через телнет. Запряг весь наш саппорт при таких симптомах ничего не делать, кроме поднимания меня из гроба.
И вот сегодня как раз удачно сошлись звезды: опять баг, саппорт меня саммонил, у клиента нормальный сервак, сервис обновлен, консоль есть, можно спокойно изучать.
Включил консолью всю отладку, сижу втыкаю в DebugView/OutputDebugString, параллельно рассматривая код.
И вижу странное: все работает, кроме функции которая скидывает данные из расчетного кэша в БД. А функция, в целях снижения нагрузки на БД окружена таймером, который разрешает ей работать не чаще чем раз в определенное время, обычно 15 секунд. И, что характерно - реализовано это на GetTickCount, который хоть и склонен к переполнению, но при адекватной реализации это не мешает. А реализация там, ВНЕЗАПНО, неадекватная - два обращения к GetTickCount, вместо одного.
Смотрю значение GetTickCount - 1.25 дня. Смотрю данные - последний раз пришли в 7 часов утра. Туплю. Потом доходит - 7 часов утра ВЧЕРА, т.е. 1.25 дня назад. С приездом вас, называется.
Сервис останавливать нежелательно - надо бы и данные скинуть в базу, а то потом придется делать немного хитроватую процедуру их повторной передачи.
Значит, что я делаю:
1) Достаю строго нужную версию сервиса из SVN.
2) Собираю с отладочной информацией.
3) Копирую файлы отладочной информации клиенту рядом с его работающим сервисом.
4) Ставлю Debugging tools for Windows
5) Подключаюсь к сервису
6) Ставлю bp на нужный метод.
7) Ловлю вызов.
8) Дохожу до реализации if в виде cmp edx, eax / jbe ...
9) Меняю значение регистра edx на правильное, метод идет работать как положено.
10) Profit. Данные скинулись в базу. Переменная установилась в кошерное значение. Еще есть 49 дней до следующего переполнения, можно успеть починить исходники.
Проявился, значит, в одном из сервисов, призванных работать 24/7, странный баг.
Все работает, никаких исключений, никаких признаков ничего плохого - но данные в базу не попадают. Появляется ну раз в месяц, может быть. Бесил, ибо был необъясним.
Добавил в сервис консоль удаленного управления, через телнет. Запряг весь наш саппорт при таких симптомах ничего не делать, кроме поднимания меня из гроба.
И вот сегодня как раз удачно сошлись звезды: опять баг, саппорт меня саммонил, у клиента нормальный сервак, сервис обновлен, консоль есть, можно спокойно изучать.
Включил консолью всю отладку, сижу втыкаю в DebugView/OutputDebugString, параллельно рассматривая код.
И вижу странное: все работает, кроме функции которая скидывает данные из расчетного кэша в БД. А функция, в целях снижения нагрузки на БД окружена таймером, который разрешает ей работать не чаще чем раз в определенное время, обычно 15 секунд. И, что характерно - реализовано это на GetTickCount, который хоть и склонен к переполнению, но при адекватной реализации это не мешает. А реализация там, ВНЕЗАПНО, неадекватная - два обращения к GetTickCount, вместо одного.
Смотрю значение GetTickCount - 1.25 дня. Смотрю данные - последний раз пришли в 7 часов утра. Туплю. Потом доходит - 7 часов утра ВЧЕРА, т.е. 1.25 дня назад. С приездом вас, называется.
Сервис останавливать нежелательно - надо бы и данные скинуть в базу, а то потом придется делать немного хитроватую процедуру их повторной передачи.
Значит, что я делаю:
1) Достаю строго нужную версию сервиса из SVN.
2) Собираю с отладочной информацией.
3) Копирую файлы отладочной информации клиенту рядом с его работающим сервисом.
4) Ставлю Debugging tools for Windows
5) Подключаюсь к сервису
6) Ставлю bp на нужный метод.
7) Ловлю вызов.
8) Дохожу до реализации if в виде cmp edx, eax / jbe ...
9) Меняю значение регистра edx на правильное, метод идет работать как положено.
10) Profit. Данные скинулись в базу. Переменная установилась в кошерное значение. Еще есть 49 дней до следующего переполнения, можно успеть починить исходники.
![[identity profile]](https://www.dreamwidth.org/img/silk/identity/openid.png){kind=small}
no subject
Date: 2012-01-04 11:21 am (UTC)no subject
Date: 2012-01-04 11:23 am (UTC)no subject
Date: 2012-01-04 11:33 am (UTC)отладочная информация, gdb, аттач к процессу и далее аналогично :)
no subject
Date: 2012-01-04 12:13 pm (UTC)no subject
Date: 2012-01-04 12:27 pm (UTC)no subject
Date: 2012-01-04 01:37 pm (UTC)no subject
Date: 2012-01-06 08:53 am (UTC)no subject
Date: 2012-01-04 01:43 pm (UTC)no subject
Date: 2012-01-04 01:48 pm (UTC)no subject
Date: 2012-01-04 02:04 pm (UTC)Кстати, если вдруг нет отладочной информацыи -- то сравнительное удобство командной строки только возрастает. То есть подобную задачу я, скорее всего, решыл бы довольно быстро и без debug symbols.
А вот собрать так, чтобы отладочная информацыя попала -- т.е. как минимум та жэ версия gdb, libgcc и скриптов линкера -- это выглядит фантастикой. Я не пробовал, но выглядит. Так что отладочные символы всегда надо спасать при релизах. И -dbg пакеты в Debian -- отнюдь не блаж, а рабочий инструмент сисадмина.
no subject
Date: 2012-01-04 02:27 pm (UTC)no subject
Date: 2012-01-04 12:49 pm (UTC)no subject
Date: 2012-01-04 12:59 pm (UTC)Telnet там только к моему сервису и только на 127.0.0.1
а вообще да, gdb
no subject
Date: 2012-01-04 01:42 pm (UTC)>Ни одной перезагрузки, мне ж нужно было сервис запущенным пофиксить :)
ну, когда я ставил виндбг, мне пришлось перестартовать винду с какими-то хитрыми параметрами, но это было давно и таки да, в принципе, винда могла бы быть уже запущена в нужной позе.
no subject
Date: 2012-01-04 11:24 am (UTC)no subject
Date: 2012-01-04 11:30 am (UTC)респект и уважуха.
т.е. баг проявлялся, если в сервисе 24/7 случалось снижение нагрузки и в течение суток не было запросов? я правильно понял?
no subject
Date: 2012-01-04 11:32 am (UTC)no subject
Date: 2012-01-04 11:33 am (UTC)а то собирался уточнять откуда число 49.
Ювелирная программная гинекология
Date: 2012-01-04 11:37 am (UTC)no subject
Date: 2012-01-04 11:45 am (UTC)no subject
Date: 2012-01-04 11:52 am (UTC)У меня руки никак не дойдут этот кэш оформить теоретически верно.
no subject
Date: 2012-01-04 12:03 pm (UTC)no subject
Date: 2012-01-04 12:52 pm (UTC)Вот и вылезло кривое переполнение в знаковый разряд.
no subject
Date: 2012-01-04 12:59 pm (UTC)no subject
Date: 2012-01-04 01:47 pm (UTC)А. понял. не хватило диапазона. типа реально ничего не делали 257 времени, а по арифметике насчитали 1 времени. Тогда да, надо или диапазон расширять, или принудительно сбрасывать при переполнении.
no subject
Date: 2012-01-04 01:52 pm (UTC)А при следующем запуске этой процедуры GetTickCount вернул чо-то вроде 0000хххх
сравнение возвращает false всегда, сохранение в базу не выполняется, старое значение не изменяется. Если бы было вычитание - все было бы кошерно.
no subject
Date: 2012-01-04 02:04 pm (UTC)хотя, хз. Компилировать тесты - лень.
no subject
Date: 2012-01-04 02:10 pm (UTC)no subject
Date: 2012-01-04 12:57 pm (UTC)а что нынче кошерное по типу SoftIce присутствует?
no subject
Date: 2012-01-04 01:03 pm (UTC)no subject
Date: 2012-01-04 01:49 pm (UTC)no subject
Date: 2012-01-05 10:53 am (UTC)no subject
Date: 2012-01-05 11:11 am (UTC)Вот-вот. Даже отэнумерейтить по-человечески не могут.
no subject
Date: 2012-01-05 10:54 am (UTC)no subject
Date: 2012-01-04 01:12 pm (UTC)no subject
Date: 2012-01-04 01:49 pm (UTC)если машина антикварная, без пси-экспресс, то скорее всего софтайс заведется.
no subject
Date: 2012-01-04 04:04 pm (UTC)no subject
Date: 2012-01-04 04:54 pm (UTC)no subject
Date: 2012-01-04 01:40 pm (UTC)Отличие было в том что софт был в Киеве, я в Минске, канал был тощий.
Брякпоинт отлавливался с задержкой такой нехилой :)
Фокус бага был в том что приходил мега пакет XML из данных которого
формировалась динамически форма с контролами. Юзер натасканный на горячие клавиши
иногда успевал жмякнуть на хоткей до того как объект формы был готов и отрендерен.
no subject
Date: 2012-01-04 06:25 pm (UTC)no subject
Date: 2012-01-04 06:28 pm (UTC)no subject
Date: 2012-01-05 05:05 am (UTC)no subject
Date: 2012-01-04 10:58 pm (UTC)no subject
Date: 2012-01-04 11:14 pm (UTC)no subject
Date: 2012-01-04 11:37 pm (UTC)no subject
Date: 2012-01-05 07:28 pm (UTC)no subject
Date: 2012-01-06 04:10 am (UTC)