Самый сложный баг Дэйва Баджета

Перевод интервью с Дэйвом Баджетом (Dave Baggett). Разработчик отвечает на вопрос: Какой самый сложный баг вам когда-либо приходилось отлавливать?

Довольно неприятно переживать все это снова. Будучи программистом, вы учитесь в первую очередь искать ошибку в коде, во вторую тоже, и в третью… И только в десятитысячную – в компиляторе. И вот когда спустя еще несколько тысяч попыток вы не найдете ошибки и в компиляторе, у вас остается последнее место, где еще что-то может быть не так – это железо.

Итак, вот моя история борьбы с хардварным багом.

Одна из моих задач в процессе разработки Crash Bandicoot’a заключалась в написании кода для сохранения/загрузки игры на карту памяти. Как для любого чванливого кодера, такой кодинг похож на прогулку в парке: я был уверен, что эта работа займет всего несколько дней. Но все закончилось спустя шесть недель. Нет, конечно же, я не тратил время только на этот баг, но над проблемным, как мне казалось, кодом, я проводил по несколько часов в два—три дня. Это были настоящие мучения.

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

Проблема заключалась в том, что при попытках сохранить игру, т.е. получить доступ к карте памяти, которые в абсолютном большинстве случаев были успешны, время от времени завершались неудачно из-за тайм-аута… причина которого была совершенно неизвестна! Короткая запись и та могла повредить все данные на карте. Игрок мог попытаться сохранить прогресс, но не только не сохранил бы его, но и уничтожил бы все имевшиеся до того на носителе данные.

Через некоторое время Кони Бут, наш продюсер из Sony, начала волноваться. Мы не могли выпустить игру с таким багом, а спустя шесть недель у меня не было ни единой мысли, откуда могла эта ошибка появится. Мы спросили наших коллег по работе с PlayStation, не сталкивались ли они с подобной проблемой. Нет. Ни у кого никогда не было подобных проблем с системой обработки данных карт памяти.

В случае, когда у вас больше нет идей, как справиться с возникшим багом, остается последнее средство: принцип «разделяй и властвуй» – вы начинаете делить код, отсекая от него куски, пока ошибка проявляет себя, а затем исправлять ее уже в меньшем, чем целый проект, коде.

Но не забывайте, что работа шла над проектом видеоигры, а стало быть, отсекать от проекта куски было делом непростым. Как вы можете продолжать запускать игру, если отбросили симулятор гравитации? или код рендеринга персонажей?

В таком случае приходится не совсем отбрасывать отдельный кусок кода, а заменять его более простым, достаточно тривиальным для того, чтобы быть уверенным, что ошибка возникает не в нем. А подобный рефакторинг, фактически, пересоздание игры — процесс болезненный и долгий.

Вкратце история такова: я избавился от ошибки. Я продолжал отсекать и отсекать куски кода, пока не остался только код запуска игры, который только подготавливал систему к запуску, инициализировал оборудование рендеринга и т.п. Естественно, я не мог поместить сюда меню сохранения/загрузки, потому что отсутствовал графический интерфейс. И поэтому это происходило все как бы в невидимом режиме.

В конце концов у меня остался совсем небольшой фрагмент кода, который все еще порождал ошибку – и все так же случайно! Большую часть времени все происходило, как нужно, но время от времени баг снова проявлял себя. Уже почти ничего не осталось от кода Crash’a, но запись данных по-прежнему периодически завершалась с тайм-аутом. Дальнейшие действия предпринимать было затруднительно: оставшийся код, фактически, не делал вообще ничего.

Когда у вас больше нет идей, как справится с возникшим багом, остается последнее средство: принцип «разделяй и властвуй».

И в один момент – около 3 часов ночи – мне в голову пришла одна мысль. Чтение и запись имеют точную привязку ко времени. C чем бы вы ни работали – флешкой, Bluetooth-устройством – низкоуровневый код чтения/записи имеет строгую привязку ко времени.

Часы CPU позволяют синхронизировать действия оборудования, не подключенного напрямую к процессору, с самим процессором. CPU clock задает скорость изменения информационного параметра (baud rate), т.е., фактически, скорость чтения и записи информации, и если часы сбиваются, то сбиваются и программное, и аппаратное обеспечение. Это очень, очень плохо, и обычно приводит к порче данных на носителе.

Так что же в нашем коде запуска приводило к сбою часов? Я изучил игру на предмет влияющего на часы кода и заметил, что программный таймер PS1 был установлен на частоту 1 КГц, что значительно превышало 100 Гц, на которых по умолчанию начинала работать приставка при запуске. Частота программных часов большинства игр составляла те же 100 Гц.

Энди, ведущий и единственный разработчик, участвовавший в проекте, кроме меня, установил таймер на 1000 Гц, чтобы движения были более плавными. Энди не прочь использовать ресурсы системы в полном объеме, и для хорошей симуляции гравитации нам было необходимо производить вычисления с максимальной возможной точностью и частотой.

А что если повышение частоты программных вычислений так накладывалось на общую частоту вычислений, что как-то сбивало частоту процессора PS1, нарушая обмен данными с картой памяти?

Я закомментировал проблемный код. Но это еще не означало, что баг исправлен: ведь ошибка возникала не всегда. Может быть, мне просто везло?

Прошло несколько дней, я игрался с тестирующей системой, и проблемы больше не возникало. Тогда я вернулся к полному коду Crash’а, исправив код так, чтобы перед записью или чтением данных с карты памяти частота устанавливалась на 100 Гц, а затем возвращалась к исходному значению в 1 КГц. И больше никогда эта проблема с сохранением/загрузкой игры не возникала.

Но почему?

Я снова и снова возвращался к тестирующей программе, чтобы выявить хоть какие-то причины появления ошибки при установлении таймера на частоту 1КГц. Наконец я заметил, что ошибки появлялись тогда, когда кто-то играл с джойстиком PS1. В силу того, что я сам не пользовался контроллером – к чему мне это в процессе тестирования чтения/записи? – я этого не замечал. Но вот однажды меня позвал к себе один из наших художников – тут я был уверен, что меня прокляли – при моем появлении он нервно вертел в руках джойстик приставки, и сказал, что сохранить игру вновь не удалось. «Что? Эй, повтори-ка, что сделал сейчас!»

Таким образом совпали две такие вещи: начало записи на карту памяти, игра с джойстиком – и результатом всего этого становилось повреждение данных на носителе. Для меня это однозначно выглядело как аппаратный баг.

Я пришел к Кони и рассказал, что обнаружил. Она связалась с одним из инженеров, разрабатывавших PS1. «Невозможно,» – ответили нам, – «это не аппаратная ошибка». Я попросил ее дать мне связаться с ним.

Он позвонил мне, и мы пытались отстоять свою точку зрения в споре: он – на ломаном английском, я – на еще более ломаном японском. Наконец я сказал, что готов выслать ему тестирующую программу в 30 строчек, при выполнении которой возникнет ошибка, если в это время манипулировать контроллером. Он согласился, рассказав, как он сейчас сильно занят, и соглашается на эту трату времени только потому, что мы были очень важным партнером для Sony. Я послал ему фрагмент кода тестирующей программы, демонстрирующей проявление ошибки.

Следующим вечером (мы были в Лос-Анжелесе, а он в Токио, так что для меня начало его рабочего дня было уже вечером) он позвонил мне и извинился. Это действительно была проблема с оборудованием.

В последствии я так и не узнал, в чем же именно была проблема, но общее представление после услышанного от инженеров Sony у меня сложилось примерно следующее: установление достаточно высокой частоты вычислений имело пагубное влияние на находящееся рядом с часами материнской платы оборудование. В частности, там же находился контроллер скорости записи/чтения данных с карты памяти, который задавал и скорость приема и обработки сигналов с контроллеров. Я не слишком-то разбираюсь в оборудовании, поэтому в этом вопросе плаваю.

Но суть проблемы заключалась в том, что при одновременной обработке данных с карты памяти и контроллеров, работающих обособленно друг от друга, если частота программы установлена на 1 КГц, некоторые биты пропадут, и потому данные будут потеряны, а карта памяти повреждена.
Это единственный случай в моей практике, когда суть бага объяснялась квантовой механикой.

Наставления потомкам

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

Кое-кто сказал, что мне не мешало бы набраться знаний в электронике. Полностью согласен: я считаю себя программистом «с полным набором», но граница этого набора находится где-то в области программирования на языке ассмеблера, а не игры с транзисторами. Вероятно, когда-нибудь я узнаю больше о «бренном железе».