суббота, 22 мая 2010 г.

[prog.bugs] Маленький рассказ о баге в SObjectizer

Позавчера исправил баг в SObjectizer-е. История с этим багом оказалась очень интересной: в реальной жизни сработали сразу два “закона подлости”.

Первый.

“В любой работающей программе есть, как минимум, три бага. При исправлении любого из них в программу вносится еще, как минимум, три бага.”

В начале мая удалось обнаружить причину проблемы с ACE-овским реактором при рестарте SObjectizer. Устранил эту проблему. Реактор начал работать. Но некоторые unit-тесты стали подвисать при завершении своей работы. Оказалось, что мое исправление содержало ошибку, приводившую в некоторых случаях к тупикам. Вот так, одну ошибку исправил – одну новую внес. Закон сохранения, однако ;)

Второй.

“Не верь глазам своим!”

Поиск ошибки занял много времени и отнял много сил. Из-за того, что я поверил тому, что увидел в отладчике.

Ошибка была нестабильной. Чтобы ее спровоцировать пришлось гонять в бесконечном цикле набор unit-тестов. Иногда она проявлялась на первой сотне запусков, иногда гораздо позже. Но рано или поздно один из unit-тестов зависал. Тогда я запускал Visual Studio, подключался к подвисшему процессу и смотрел, что у него внутри.

Внутри были все признаки классического тупика: две нити, одна висит на одном mutex-е, вторая на втором. Только у одной нити нормальный call stack, а вот у второй – очень и очень странный. В нем только одна запись, указывающая куда-то в дебри ACE-овской реализации Thread_Mutex-а. А в контексте вызова все указатели явно недействительные. Что наводило на мысль, что где-то затиралась память, из-за чего портился, в том числе, и call stack. Это был первый ложный след.

Ошибка возникала изначально только на unit-тестах, в которых проверялось наследование агентов. Это был второй ложный след.

Поэтому долго я пытался разобраться, как наследование агентов приводит к порче памяти. В качестве подтверждения такого предположения сыграло еще и то, что я нашел unit-тест, который стабильно подвисал на 100-150 запусках. Когда я сильно урезал его, убрав наследование, он не зависал и после 2000 запусков.

Ситуация становилась очень странной. Механизм наследования, который стабильно работал многие годы, вдруг засбоил. Причем не только под VC++ 9.0, но и под VC++ 7.1, не только под ACE 5.7.8, но и под ACE 5.6.8. Верить в такой сбой мне не хотелось, хотя показания отладчика недвусмысленно указывали на то, что память таки портится.

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

Вскоре после этого ошибка нашлась. Как водится, ларчик открывался просто. На рабочей нити реактора я вызывал reset_reactor_event_loop() и входил в цикл обработки событий реактора. На основной нити приложения выполнялись действия теста, после чего вызывался метод end_reactor_event_loop() и выполнялось ожидание завершения рабочей нити реактора. Так вот, когда тест отрабатывал очень быстро, метод end_reactor_event_loop() вызывался еще до того, как рабочая нить реактора в первый раз получала управления. Т.е. признак завершения работы реактора уже был выставлен, но я его сбрасывал посредством reset_reactor_event_loop() и входил в цикл обработки событий реактора. Которых уже не могло быть в принципе. Обычные гонки двух нитей. Почему Visual Studio не смогла показать в этой ситуации нормальный call stack – фиг знает. Еще один повод бросить какашку в мелкомягкий софт :)

В заключение хочется сказать о везении. Мне очень крупно повезло, когда я случайно наткнулся на этот баг. Помнится, я проводил контрольную компиляцию под Linux-ом и GCC 4.4.1 ругнулся на какую-то банальную ошибку в каком-то из тестов (вроде забытого #include <cstdio>). Ошибку под Linux-ом я исправил, но для очистки совести решил повторить контрольную компиляцию и под Windows. И тут-то один из unit-тестов завис. Потом несколько компиляций прошло нормально, но зерна сомнения во мне уже зародились. Прогнал еще несколько циклов unit-тестов и зависание повторилось. Тогда я понял, что shit таки happened и нужно копать.

Вот так. Повезло.

Комментариев нет: