metaclass: (Default)
metaclass ([personal profile] metaclass) wrote2012-01-04 02:12 pm

Удачное начало нового года или программистская гинекология.

"Сначала мы себе создаем проблемы, а потом их героически решаем."

Проявился, значит, в одном из сервисов, призванных работать 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] falcrum.livejournal.com 2012-01-04 11:21 am (UTC)(link)
Гинеколог-ювелир! :)

[identity profile] hshhhhh.livejournal.com 2012-01-04 11:23 am (UTC)(link)
Шаман :). А в линуксах такое как сделать?

[identity profile] skif-by.livejournal.com 2012-01-04 11:24 am (UTC)(link)
Гинеколог-хирург. А вообще, ребе, просто восхитительно! Снимаю шляпу :)

[identity profile] trueblacker.livejournal.com 2012-01-04 11:30 am (UTC)(link)
зашебенно! круче любого детектива.
респект и уважуха.
т.е. баг проявлялся, если в сервисе 24/7 случалось снижение нагрузки и в течение суток не было запросов? я правильно понял?

Ювелирная программная гинекология

[identity profile] pingback-bot.livejournal.com 2012-01-04 11:37 am (UTC)(link)
User [livejournal.com profile] skif_by referenced to your post from Ювелирная программная гинекология (http://skif-by.livejournal.com/129669.html) saying: [...] Вот тут [...]

[identity profile] trueblacker.livejournal.com 2012-01-04 11:45 am (UTC)(link)
а всё таки интересно, как работает кэш. Я так понял, что он собрался ждать 49 дней до выполнения транзакции. Но у него что, нет никакого flush если он переполняется не по времени а по размеру очереди?

[identity profile] abadonne.livejournal.com 2012-01-04 12:03 pm (UTC)(link)
Очень круто!

[identity profile] nicka-startcev.livejournal.com 2012-01-04 12:52 pm (UTC)(link)
как я понимаю, значение счетчика - величина со знаком, да?
Вот и вылезло кривое переполнение в знаковый разряд.

[identity profile] jdevelop.livejournal.com 2012-01-04 12:57 pm (UTC)(link)
респект, уважуха

а что нынче кошерное по типу SoftIce присутствует?

[identity profile] fas-tm.livejournal.com 2012-01-04 01:40 pm (UTC)(link)
Я помню таким же образом ловил багу.
Отличие было в том что софт был в Киеве, я в Минске, канал был тощий.
Брякпоинт отлавливался с задержкой такой нехилой :)

Фокус бага был в том что приходил мега пакет XML из данных которого
формировалась динамически форма с контролами. Юзер натасканный на горячие клавиши
иногда успевал жмякнуть на хоткей до того как объект формы был готов и отрендерен.

[identity profile] exemok.livejournal.com 2012-01-04 06:25 pm (UTC)(link)
Ребе, а это точно была не проктология?

[identity profile] cottidianus.livejournal.com 2012-01-04 10:58 pm (UTC)(link)
всё правильно сделал

[identity profile] rigidus.livejournal.com 2012-01-04 11:14 pm (UTC)(link)
Однако, судя по кол-ву восхищенно-испуганных комментов ныне это уже забытое шаманское искусство... Жаль. Я много времени провел под отладчиком в конце девяностых...