?
Ни о какой безапелляционности в моих высказываниях не может быть и речи! [entries|archive|friends|userinfo]
Anatoly Vorobey

[ website | Website ]
[ userinfo | livejournal userinfo ]
[ archive | journal archive ]

Links
[Links:| English-language weblog ]

шаг вперед, два шага назад (программистское) [авг. 20, 2010|03:40 am]
Anatoly Vorobey
(интересно будет скорее всего только программистам)

Пару недель назад я починил баг на работе в одной внутренней библиотеке. Этот баг проявлялся так: долгоживущие сервера, пользовавшиеся этой библиотекой определенным способом, загадочным и случайным образом падали примерно раз в неделю (не все одновременно, а каждый сервер отдельно падал примерно с такой частотой). Найти и починить баг оказалось очень тяжело, потому что к моменту падения следов никаких почти не оставалось. Сам по себе баг тривиален - многопоточный код недостаточно дисциплинированно охранял доступ к глобальному ресурсу, который я назову X. У X есть мьютекс, который надо получить перед тем, как его трогать. Два потока делали следующее:

thread 1: get-mutex-for-X change1-X release-mutex-for-X
thread 2: change2-X

Код, который меняет X, в двух потоках был разный, поэтому я обозначил его change1 и change2, но он трогал одну и ту же часть X, и второй поток банально не охранял свой доступ мьютексом. Изредка, очень изредка, эти два потока выполняли эти куски кода одновременно на разных ядрах. Отыскать это все быстро мешало несколько осложняющих обстоятельств:

- кроме этих двух мест, есть еще десятки мест, которые меняют X, правильно охраняя замену мьютексом, но ни один из них не может конфликтовать с "thread 2"
- сам конфликт между thread 1 и thread 2 не приводил к немедленному падению, а коррумпировал внутренние структуры X, что обычно приводило к падению с загадочной и невнятной ошибкой спустя несколько секунд. К тому времени обычно thread 1 и thread 2 давно уже ушли из этих частей кода и никак не проявлялись в stack trace. Обычно там проявлялись другие места, которые ждали mutex-for-X в момент падения, просто по случайности.
- тот факт, что thread 2 не пользовался мьютексом, не был очевиден из его кода - неважно почему, долго объяснять. Казалось бы, этот код полностью лежал, вместе с еще кучей всего, внутри мьютекса X, но на самом деле он освобождал мьютекс как раз перед change2, и потом брал его заново, и это было неочевидно при чтении кода. Т.е. thread 2 выглядел, если быть точнее, так - троеточие передает "много всякой всячины":
thread 2: get-mutex-for-X ... release-mutex-for-X change2-X get-mutex-for-X ... release-mutex-for-X

Во многих ситуациях такое временное освобождение мьютекса как раз правильное поведение - если бы change2-X не меняло X, а делало какие-то совершенное другие вещи, и притом не очень быстро, то как раз это правильно. Но в данном случае это ошибка.

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

thread 1: get-mutex-for-X change1-X release-mutex-for-X
thread 2: get-mutex-for-X ... change2-X ... release-mutex-for-X

Падений больше не было. Вскоре я уехал в отпуск.

Во время моего отпуска, который еще не закончился, выяснилось следующее. Кусок кода из "thread 2" меняет X и одновременно меняет другой глобальный ресурс Y, который защищен своим собственным мьютексом. Изменение Y происходит внутри "change2-X" с помощью вызова какой-то функции Y, и работа с мьютексом полностью спрятана внутри этой функции и незаметна при чтении кода thread 2. Тем не менее, эта работа происходит, и если ее учесть, thread 2 выглядит так:

thread 2: get-mutex-for-X ... get-mutex-for-Y ... release-mutex-for-Y change2-X ... release-mutex-for-X

Одно из десятков других мест, которые могут менять X и охраняют это мьютексом, происходит внутри кода, связанного с ресурсом Y, и находящегося глубоко внутри цепочки кода, охраняемой мьютексом для Y. Этот код, выходит, выглядит так:

thread 3: get-mutex-for-Y ... get-mutex-for-X change3-X release-mutex-for-X ... release-mutex-for-Y

Интересно, что изменения change2-X и change3-X никак не конфликтуют друг с другом - они меняют разные места X. Но из-за того, что thread 2 и thread 3 получают два мьютекса для X и Y в разном порядке, получается возможность взаимной блокировки (deadlock). Один поток получил мьютекс для X, и еще до того, как он попытался получить мьютекс для Y, второй поток получил его - и все, они зависают, пытаясь отобрать друг у друга те мьютексы, что у них есть. До того, как я исправил код thread 2, блокировки быть не могло, но теперь она возможна.

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

Коллега, который разобрался в этой мешанине и нашел мою ошибку, исправил код thread 2 следующим образом. Он вернул освобождение мьютекса-X перед основной работой этого кода, и вставил эксплицитное ожидание этого мьютекса снова - но только после того, как вся работа с Y закончена. Так что выполнение thread 2 имеет теперь такой вид:

thread 2: get-mutex-for-X ... release-mutex-for-X get-mutex-for-Y ... release-mutex-for-Y get-mutex-for-X change2-X release-mutex-for-X get-mutex-for-X ... release-mutex-for-X.

На данный момент ни о каких новых проблемах с этим кодом не известно.
СсылкаОтветить

Comments:
[User Picture]From: creaturen2
2010-08-20 01:50 am
По нашей профессии тоже можно снимать фильм наподобие "Доктора Хауса".
(Ответить) (Thread)
[User Picture]From: kot_begemot
2010-08-20 01:56 am
Когда-то давным-давно был такой дивный инструмент для статического анализа многопоточного кода - locklint. Отлавливал такие ситуации довольно хорошо.
Решение коллеги, кстати, не идеально. Я бы, наверное, попытался разделить изменение X и Y по времени, более того, сделал бы доступ к полям X и Y исключительно через аксессоры/мутаторы, в которых бы и брал нужные мютексы.
Помимо всего прочего, это могло бы увеличить эффективность за счёт более высокой ганулярности сериализаций.
(Ответить) (Thread)
[User Picture]From: iratus
2010-08-20 05:07 am
Почему был? Он и сейчас прекрасно есть. Но работает только под Солярисом.
Для Линуксов есть Helgrind
(Ответить) (Parent) (Thread) (Развернуть)
[User Picture]From: larisaka
2010-08-20 02:01 am

скорее всего только программистам

Фраза "Падений больше не было. Вскоре я уехал в отпуск." как-то выпадает из стиля записи, вам не кажется? какая-то литературная. Программисты могут огорчиться.
(Ответить) (Thread)
[User Picture]From: pilpilon
2010-08-20 07:28 am

Re: скорее всего только программистам

С чего бы? Для программистов это thriller story, такая фраза там очень уместна.
(Ответить) (Parent) (Thread)
[User Picture]From: raindog_2
2010-08-20 03:01 am
По совпадению, я как раз только что прослушал tech talk насчет STM в Closure (http://www.infoq.com/presentations/Value-Identity-State-Rich-Hickey). Твою историю можно запускать как страшилку перед рекламой Clojure & friends. "Раньше я пользовался Мьютексом, и страдал изжогой, а теперь перешел на persistent data structures / managed references, и мои волосы опять стали пушистыми" :)
(Ответить) (Thread)
[User Picture]From: cema
2010-08-20 04:13 am
Ну да, только не перешел.
(Ответить) (Parent) (Thread)
From: once_for_all
2010-08-20 03:23 am
Multithreading 101 С одной стороны - rookie mistake; с другой - the bitch to debug, тем более в чужом коде..

Из любпытство - насколько необходим общий mutex для всего Х? Была ли возможность заменить на, скажем, атомик переменные, или скажем все изменения такого рода посылаются в background thread? Если бы вы начинали делать новый дизайн.
(Ответить) (Thread)
[User Picture]From: iratus
2010-08-20 05:08 am
Это далеко не rookie mistake.
(Ответить) (Parent) (Thread) (Развернуть)
[User Picture]From: cema
2010-08-20 04:15 am
А почему разные треды берут мьютексы в разном порядке? Непорядок.
(Ответить) (Thread)
From: rezkiy
2010-08-20 04:27 am
мне как-то Арун Кишан рассказывал, как он автоматизировал процесс поиска таких ошибок без собственно поиска дедлоков. Ясно дело, что если дедлокнуло, то дампы говорят сами за себя. Но иногда дедлокает редко, и есть риск шипнуть с багом.
(Ответить) (Parent) (Thread) (Развернуть)
[User Picture]From: stas
2010-08-20 05:31 am
Вот поэтому threads are evil.
(Ответить) (Thread)
[User Picture]From: lxe
2010-08-20 06:15 am
Не, зло - это блокировки. А рулят атомарные операции.
(Ответить) (Parent) (Thread) (Развернуть)
[User Picture]From: netp_npokon
2010-08-20 06:59 am
А вы не пробовали использовать ThreadSanitizer для поиска не защищенных мьютексом доступов? Если нет, то это, по-видимому, наша недоработка :)
(Ответить) (Thread)
[User Picture]From: avva
2010-08-20 08:11 am
А ThreadSanitizer мог бы помочь в этом случае, учитывая эти обстоятельства? Если да, то это по-видимому моя недоработка, что я не попробовал :)
(Ответить) (Parent) (Thread) (Развернуть)
(Удалённый комментарий)
[User Picture]From: avva
2010-08-20 05:38 pm
- смотрел на stack traces всех потоков в момент падения
- читал исходники выглядевших интересно потоков
- недоумевал
- добавлял много debug prints куда надо и не надо, перезапускал, ждал падения (около 2-х часов т.к. я запускал много копий)
- смотрел на stack traces, читал исходники, недоумевал
- читал информацию в интернете и внутренних рассылках про то, что означает невнятная ошибка в момент падения
- добавлял еще debug prints, убирал некоторые вызовы X, подозревая их, перезапускал
- смотрел на stack traces, читал исходники, недоумевал
- повторить предыдущие два пункта несколько раз

Через какое-то время мне СИЛЬНО ПОВЕЗЛО и "thread 2" еще не успел уйти из своего кода к моменту падения через несколько секунд - так сложилось, что он все еще ждал мьютекса X. Я до этого этот код в stack traces не видел, заинтересовался, начал читать, понял, что ничего не понимаю. Пошел читать документацию SWIG, который плохо знаю, разобрался, сформировал подозрение, проверил, ну дальше уже легко.

Если бы не было этого "сильно повезло", следующим этапом было бы построить debug build питона, распечатывающий все, что возможно, о внутренних структурах, и искать тот момент, когда происходит коррупция, а не падение (я понимал уже, что это два разных момента). Правда, не уверен, что на это меня бы в тот день хватило.
(Ответить) (Parent) (Thread) (Развернуть)
[User Picture]From: jasno
2010-08-20 11:34 am
до чего же типичная и знакомая ситуация:) с этим малтитредингом всегда так - убрал race - добавил deadlock, и наоборот. и race, конечно, ужасно фигово ищется.
(Ответить) (Thread)
[User Picture]From: dmarck
2010-08-20 03:02 pm
Hmm, а зачем в последнем core flow вот эта часть:

change2-X release-mutex-for-X get-mutex-for-X

?

Я упускаю что-то очевидное?
(Ответить) (Thread)
[User Picture]From: avva
2010-08-20 05:28 pm
Это не друг за другом в исходнике, а в функциях разного уровня. Внешняя функция делает

release
do stuff
get

внутренняя где-то внутри do stuff делает

do some stuff
get
do more stuff
release

Если посмотреть на то, что происходит с мьютексом, то выходит теоретически ненужная последовательность release get, но это незначительная плата за правильные абстракции.

Edited at 2010-08-20 17:28 (UTC)
(Ответить) (Parent) (Thread)
[User Picture]From: dimrub
2010-08-20 07:42 pm
У вас есть билд с tsan?
(Ответить) (Thread)
[User Picture]From: avva
2010-08-20 07:47 pm
Нет - см. выше, думаю, что это для нас нерелевантно, т.к. все происходило при координации C++ с питоном, а питон и его API и SWIG не инструментированы для тсана.
(Ответить) (Parent) (Thread) (Развернуть)
[User Picture]From: inmbt0001
2010-08-20 09:55 pm

обычная тема - плохо структурированный код

Меня в такой ситуации больше всего расстраивает то, что некоторые бинарники невозможно собрать в debug режиме, как раз недавно пытался собрать нечто, чьи объектники занимали более 5 гигов. Приходится отлаживаться старым добрым printf.

Интересно, что за библиотека это была....
(Ответить) (Thread)