Об охоте на необычного слона
Охота на жуков - это весело. И время от времени вы уходите живым с историей, которой можно побаловать внуков ("В мои времена мы еще охотились на жуков с палками и камнями" и все такое).
На GDC 2014 нас ждало еще одно охотничье сафари, достойное трофея. До презентации Unity 5 оставалось пять дней, когда мы "заметили" (ну, это было трудно не заметить) уродливую ошибку: наш блестящий новый 64-битный редактор случайно падал на OSX и становился совершенно непригодным для использования. Нет ничего лучше, чем выходить на сцену и каждые пару минут демонстрировать, насколько крут ваш репортер.
Итак, Леви, Джонатан и я бросили все дела, над которыми мы работаем (больше историй, которыми мы хотим побаловать наших внуков), и отправились на поиски. Все, что мы знали на тот момент, - это то, что сбой произошел где-то в нативном коде, который Mono генерирует во время выполнения.
Как известно каждому программисту, когда вы сталкиваетесь с неочевидной ошибкой, вы просто начинаете собирать доказательства. Как только вы узнаете достаточно о поведении жука, вы в конце концов сможете его подстрелить. А время шло, и мы были готовы стрелять практически во что угодно.
Но мы были в тупике. Для слона жук оказался на удивление проворным и хитрым.
Похоже, это происходило только на OSX 10.9, хотя Ким видел нечто похожее на Windows с его веткой отладчика памяти. А если вы включили Guard Malloc в ранних версиях OSX, то получили довольно похожую картину. Однако, поскольку сбой происходил в произвольном коде сценария на произвольной глубине в иерархии вызовов, было трудно с уверенностью сказать, что является одним и тем же сбоем, а что нет. И авария может быть последовательной в течение десяти последовательных заездов, а в следующие пять - совершенно другой.
Пока мы с Ким пробирались по колено в памяти и по бедро в ассемблере, Леви проследил все секретные и не очень секретные действия Mono и создал гигабайтный журнал и редактор, который работал со скоростью моей бабушки. Это позволило сделать первый интересный вывод: очевидно, мы всегда компилировали метод, в котором произошел сбой, прямо перед тем, как все пошло наперекосяк.
Но что привело к аварии? Непосредственная причина заключалась в том, что мы пытались выполнить код с неправильного адреса. Как мы туда попали? Ошибка в обработке сигналов Mono, когда мы не возобновляем работу должным образом? Ошибка в JIT-компиляторе Mono, которая не позволяет правильно вернуться к скомпилированному коду? Другой поток повреждает память стека в главном потоке? Феи и ворчуны? (На какое-то время последнее показалось наиболее вероятным).
После двух дней охоты слон был все еще жив и находился на свободе.
Итак, в субботу вечером я вооружился блокнотом, четырьмя разными цветными ручками и достаточным запасом пива из нашего фирменного холодильника Unity (тщательно следя за тем, чтобы не трогать ужасное баночное рождественское пиво, которое до сих пор хранится в его щелях). Затем я запустил экземпляры Unity, пока в отладчике не появились четыре разных сбоя, обозначил их как "Red Crash", "Blue Crash", "Green Crash" и "Black Crash" и принялся за работу, соответственно, с цветными ручками, чтобы сделать заметки и нарисовать несколько не очень красивых диаграмм всего, что я обнаружил.
Вот мои заметки о Blue Crash:
И тогда я сделал свое первое открытие: в каждом случае стек был на 16 байт больше, чем должен быть!
Это привело к следующему открытию: для всех сбоев просмотр этих дополнительных 16 байт позволяет найти адрес возврата в функцию, в которой произошел сбой. Из трассировки было видно, что во всех случаях мы уже выполнили несколько вызовов одного и того же метода, и сначала я подумал, что адрес был получен от последнего вызова, который мы отследили. Однако при ближайшем рассмотрении выяснилось, что это был обратный адрес вызова, метод которого еще не был скомпилирован!
Это на мгновение озадачило меня, поскольку в некоторых случаях между последним отслеженным методом и этим вызовом было несколько вызовов, которые также еще не были скомпилированы. Однако при ближайшем рассмотрении выяснилось, что мы всегда прыгали вокруг них.
Тогда я посмотрел на ту функцию, с которой мы, очевидно, должны были вернуться...
Вот и все (выделено синим): Мы прыгали не в том направлении!
Здесь Mono создает маленькие "батутные" функции, которые содержат только вызов JIT-компилятора и некоторые данные, закодированные в потоке инструкций после вызова (используются JIT-компилятором, чтобы узнать, какой метод компилировать). Как только JIT-компилятор сделает свою работу, он удалит эти батуты и сотрет все следы того, что вы подключились к вызову метода.
Однако инструкция вызова, которую вы видите там, является так называемым "ближним вызовом", который, кстати, использует знаковое 32-битное смещение для перехода к следующей инструкции.
А поскольку знаковое 32-битное число может занимать всего 2 ГБ вдоль и поперек, а мы работаем на 64-битной системе, мы вдруг поняли, почему расположение кучи памяти играет такую важную роль в воспроизведении ошибки: как только батуты Mono удалялись от JIT-компилятора более чем на 2 ГБ, смещения переставали укладываться в 32 бита и обрезались при выдаче инструкции вызова.
В этот момент Джонатан быстро нашел нужное исправление, и к тому времени, когда его воскресенье закончилось, мы получили стабильную рабочую сборку, готовую к GDC.
Вы все знаете историю этого места. Мы успешно продемонстрировали Unity 5 на GDC 2014, получив восторженные отзывы, а после запуска она быстро стала самой любимой частью программного обеспечения за всю историю. О, подождите, это еще впереди...
До этого запуска нужно исправить еще много черных и синих аварий :).