Как EA усложнили нам жизнь, или как мы чинили баг 12-летней давности

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

Лирика

Речь пойдет об игре Need for Speed: Most Wanted. Эта игра очень популярна и крайне любима многими геймерами-энтузиастами, и многими считается чуть ли не лучшей в серии. Даже если вы не азартный игрок, то наверняка слышали об этой игре в частности или о серии в целом. Но обо всем по порядку.

Я – спидранер. Прохожу игры на скорость. Довелось мне быть одним из первопроходцев в деле скоростного прохождения гоночных игр, поэтому я заодно являюсь одним из «глобальных модераторов» спидран-коммьюнити серии NFS. Участь со мной разделил чех под ником Ewil.

Почему участь? Потому что в один прекрасный момент к нам в дискорд-сервер пришел человек и заявил, что все наши рекорды трасс неправильны, и что мы – нубы. Скрепя сердце, подавляя багет от, как казалось, необоснованного обвинения и борясь с языковым барьером (английским этот человек владеет на очень плохом уровне), мы начали разбираться, что же не так с нашими рекордами. Из обрывков речи мы поняли, что в игре есть некий «timebug», который делает IGT неправильным. Ewil пересмотрел некоторые записи и руками пересчитал время. Оказалось, нам не врали. На записях IGT резко отличалось от RTA. Это были не пара миллисекунд, которые тоже могу решить исход рекорда, а местами разница доходила даже до нескольких секунд(!).

Мы начали искать причину и последствия этого явления. Еще задолго до этого я в личных интересах пытался «вытащить» из игры IGT. Моя попытка не увенчалась успехом, и я как-то забил на эту идею. Информации в интернете мы найти не смогли, за исключением какой-то английской странички с очень коротким описанием, без какой-либо доказательной базы. Поиск по ютубу также не принес результатов, но были найдены записи, которые гласили «No TimeBug».

Чуть позже я познакомился со SpeedyHeart, и она мне подсказала, что в игре время считается как float. Тут все начало проясняться, и мы медленно переходим от унылого вступления к лютому экшону!

Как это работает

Вооружившись Cheat Engine, OllyDbg, DxWND и NFS: MostWanted версии 1.3, я полез рыться в памяти. Выкопал я примерно вот что (картинка кликабельна):



Нас интересуют последние три адреса. Они хранят в себе IGT для разных ситуаций. Почему они float – одному Блэк Боксу известно… Но так не делают! Float, у него же точность, как у дробовика, а может и того хуже.

Занудство

Кстати, в предыдущей игре серии время считается как int – общее количество тиков процессора (а когда оно перевалит за те самые 2 миллиарда, игра запаникует и предпочтет упасть). Соответственно, этот модуль их движка был переписан, но лучше не стало. В предыдущей части, кстати, IGT тоже отличается от RTA, но там это, скорее всего, вызвано подлагиванием движка.

Собственно, немного о самих таймерах. Таймеры хранят время в секундах, т. е. целая часть – количество полных секунд. Два из этих таймеров, а именно Global IGT и Race IGT, периодически обнуляются. Для Global IGT это происходит в момент выхода в главное меню, а Race IGT обнуляется при рестарте гонки. Подсчет IGT производится через Global IGT, и в какой-то момент времени ему уже не хватает точности. Из-за этого время считается неправильно.

На этой стадии меня заинтересовали несколько вопросов:

1. Раз уж есть разница во времени, то отличается ли геймплей с багом и без? Логично предположить, что если IGT ускоряется, то и в целом игра должна становиться «быстрее»
2. Какие рамки у этого бага? Как он будет себя вести при разных значениях таймера, и как на это будет реагировать игра.

Ответ на вопрос номер 1 был найден крайне быстро. Я просто взял и изменил показания Global IGT на 300000.0 и получил то, что получил. Время ускорилось почти в два раза(!), однако на физике и поведении игры это никак не отразилось. Прикола ради я тыркал и другие таймеры, но они, почему-то, ни на что не влияют. Собственно, если бы с ускорением времени ускорялся и геймплэй, то в нашем мире спидранерства это считается вполне законным. Все таки мы любим баги. Но такой расклад никого не устроил.

Я пошел немного глубже и нашел ответ на вопрос 2. Как только Global IGT достигает отметки в 524288 время в игре полностью останавливается. Это немного смущает игру, и она начинает плохо себя вести делать интересные вещи. Например, не дает начать гонку после рестарта, намертво блокируя игру (выйти из нее можно только через диспетчер задач или Alt+F4). Отрыв/отставание от соперников перестает работать. А если проиграть гонку, то игра отправляет вас в свободное плавание по миру.

Float — ад перфекциониста.

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

Перед непосредственно кодом, распишу немного про цели. Известно, что игра «блокирует» цикл обновления физики на 120 раз в секунду (опять же, спасибо SpeedyHeart за информацию). Однако vsync обрубает обновление физики еще сильнее, до 60 раз в секунду. Соответственно, мы просто возьмем float-переменную и будем циклически туда добавлять 1/60 секунды. Потом мы посчитаем, за сколько шагов мы добились результата, и за сколько шагов мы должны были добиться этого результата. Также будем делать все циклически для разных случайных величин и считать среднюю погрешность в рассчетах. Любые отклонения в 2 и менее шагов (33мс) мы будем считать незначительными, потому что игра показывает время до сотых секунды.

#include <stdio.h>
#include <stdlib.h>
#include <time.h>
#include <math.h>
#include <conio.h>

#define REPEATS 1000       // Количество проверок
#define ESCAPE 27          // Код клавиши ESCAPE
#define TEST_TIME 2        // Время, проведенное на трассе
#define START_TIME 0       // Изначальное значение внутриигрового таймиера

void main( )
{
	time_t t;
	srand( time( &t ) );
	while ( true )
	{
		float diffs[ REPEATS ];
		int   frame_diffs[ REPEATS ];   // Сторэйдж разниц
		for ( int i = 0; i < REPEATS; i++ )
		{
			int limit = rand( ) % TEST_TIME + 1;// Генерируем случайное кол-во времени,
							 // +1 не даст нам сгенерировать 0
			limit *= 60;			// Минуты в секунды
			limit += (START_TIME * 60);	   // Выравниваем конечное время
			float t = 0.0f + (START_TIME*60); // Выравниваем начальное время
			float step = 1.0f / 60.0f;      	   // И лочим все на 60 фпс
			int steps = 0;
			while ( t < limit )
			{
				steps++;
				t += step;
			}

			// Считаем ожидания и выводим их на экран
			double expectation = (double)(limit - START_TIME*60)/ ( 1.0 / 60.0 );
			printf("%f\n", t );
			printf("Difference = %f; steps = %d\n", t - limit, steps );
			printf( "Expected steps = %f; frames dropped = %d\n", 
					expectation, (int)expectation - (int)steps );

			diffs[i] =  fabs( t - limit );
			frame_diffs[ i ] = (int)expectation - (int)steps;
		}

		// Считаем среднее и статистику
		float sum = 0;
		int frame_sum = 0;
		for ( int j = 0; j < REPEATS; j++ )
		{
			sum += diffs[ j ];
			frame_sum += frame_diffs[ j ];
		}

		printf( "Avg. time difference = %f, avg. frame difference = %d\n", 
			     sum / REPEATS, frame_sum / REPEATS  );
		// В случае "any key" продолжаем, в случае "ESCAPE" выходим
		printf( "Press any key to continue, press esc to quit\n" );
		if ( getch() == ESCAPE )
			break;
	}
}

Меняя значения START_TIME и TEST_TIME мы можем получить необходимую нам статистику. В целом, пока START_TIME не превышает 15 минут, то обычный 2-х минутный заезд окажется «свободным» от бага. Разница остается не критичной в рамках игры, 1-2 кадра:



16 Минут же оказались «критической точкой», когда время беспощадно плывет:



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



Поигравшись со значениями еще немного я оценил, что в получившейся программе «время» течет примерно так же, как в игре. Это было подтверждено практически – любые рекорды, записанные «из главного меню» в течение первых 15 минут геймплея были чистыми. При START_TIME близкому к 300000 секунд количество шагов было почти в два раза меньше, чем ожидалось. При START_TIME, большем магической константы 524288 программа переставала работать. Все это подтверждало, что процесс подсчета времени был скопирован верно.

Еще нудности

Результаты вычислений будут отличаться, если игра отрабатывает больше чем 60 кадров в секунду. При 120 кадрах в секунду значение «свободной от бага зоны» составляет 7 минут. Да и время останавливается значительно раньше. В двух словах, чем быстрее работает игра, тем сильнее становится ошибка.

Устраняем нежелательное поведение

Теперь, когда известна проблема и ее поведение, можно ее устранить. Нужно лишь перезаписывать Global IGT всякий раз, когда игрок начинает заезд заново. Это можно узнать довольно просто – в этот момент обнуляется Race IGT. Но тут есть проблема.

Есть два издания игры: NFS: Most Wanted и NFS: Most Wanted Black Edition. Второе издание включает в себя две дополнительные машины и две трассы, да 69-ое испытание. Но, технически, это две совершенно разные игры! Их запускаемые файлы отличаются. Помимо этого, есть патч 1.3… Который отличается для каждого издания. В итоге у нас есть 4 разных версии игры, которые надо поддерживать. Этот факт делает «правильный» путь чрезмерно сложным и неоправданным. По-хорошему, нужно слегка подправить запускаемый файл и обнулять счетчик там, но… Править 4 разных экзешника, которые еще и запакованы, да защищены от отладки… Лучше просто напишем простую программку, которая будет в реалтайме отслеживать состояние таймеров и обнулять их при необходимости. Писать будем на C#.



Вот такую архитектурку я набросал. GameProcess – это вспомогательный класс, который упрощает доступ к чтению-записи памяти процесса. GameHolder – сердце программы. Он будет инициализировать GameProcess, а при «подцепе» процесса будет определять версию игры и создавать необходимый экземпляр наследника Game. Поскольку логика «фикса» не отличается от версии к версии, то ее лучше вынести в один класс.

Как же нам определить версию? Просто – по размеру основного модуля. Я специально реализовал проперти ImageSize. А чтобы не захламлять код магическими константами, запилим enum:

enum ProcessSizes
{
    MW13 = 0x00678e4e
}

Остальные версии добавим по мере их попадания ко мне в руки.

isUnknown отвечает за тот факт, удалось ли нам определить версию или нет. Из всего класса нам интересен только метод Refresh, вот он:

        public void Refresh()
        {
            if(!process.IsOpen)
            {
                // In cases when the process is not open, but the game exists
                // The process had either crashed, either was exited on purpose
                if(game != null)
                    Console.WriteLine("Process lost (quit?)");
                game = null;
                return;
            }
            if(isUnknown) // If we couldn't determine game version, do nothing
            {
                return;
            }
            // If process is opened, but the game doesn't exist, we need to create it
            if(process.IsOpen && game == null)
            {
                Console.WriteLine("Opened process, size = 0x{0:X}", process.ImageSize);
                switch((ProcessSizes)process.ImageSize)              // Guessing version
                {
                    case ProcessSizes.MW13:
                        game = new MW.MW13(process);
                        break;
                    default:
                        Console.WriteLine("Unknown game type");
                        isUnknown = false;
                        break;
                }
            }
            // At last, update game
            game.Update();
        }

Логика фикса вышла совсем простенькой:

    public abstract class Game
    {
        private float lastTime;
        private GameProcess game;

        /// <summary>
        /// Synch-timer's address
        /// </summary>
        protected int raceIgtAddress;               
        
        /// <summary>
        /// Timer-to-sync address
        /// </summary>
        protected int globalIgtAddress;

        private void ResetTime()
        {
            byte[] data = { 0, 0, 0, 0 };
            game.WriteMemory(globalIgtAddress, data);
        }

        public void Update()
        {
            float tmp = game.ReadFloat(raceIgtAddress);
            if (tmp < lastTime)
            {
                ResetTime();
                Console.WriteLine("Timer reset");
            }
            lastTime = tmp;
        }

        public Game(GameProcess proc)
        {
            game = proc;
            lastTime = -2; // Why not anyway
        }
    }

Дело осталось за малым: реализовать версию, выставив в конструкторе необходиме значения соответствующим protected-переменным. В мэйне же просто кидаем цикл обновления в отдельный трэд и забываем про него. Ах да, из-за особенностей карточек Nvidia и особенностей реализации установщика игр NFS мы будет принимать на вход имя процесса, чтобы была возможность кастомизации.

    class Program
    {
        static void Run(object proc)
        {
            GameHolder holder = new GameHolder((string)proc);
            while (true)
            {
                Thread.Sleep(100);
                holder.Refresh();
            }
        }
        static void Main(string[] args)
        {
            Thread t = new Thread(new ParameterizedThreadStart(Run));
            t.Start(args[0]);
            Console.WriteLine("Press any key at any time to close");
            Console.ReadKey();
            t.Abort();
        }
    }

На этом фикс заканчивается. Компилируем, запускаем и забываем о таймбаге, yay! ^_^ Картинка кликабельна.



На самом деле, никуда этот баг не денется. Если один заезд физически не уложится в рамки 15 минут, то тут уже ничего не поделаешь. Но таких заездов в игре аж один, и тот от полиции.
Полные исходники на гитхабе.

Summary

Вот так один маленький баг нехило подпортил нам жизнь. А ведь его можно было избежать, если бы Black Box использовали в свое время double, но нет. Кстати, это яркий пример того, как «написанное однажды» выливается в кучу неулавливаемых/перекатывающихся багов. Timebug присутствовал в каждой игре от Black Box ever since. В Carbon, ProStreet и даже Undercover. В последнем они поменяли логику подсчета IGT, но эти три таймера там все так же присутствуют, и ошибки округления приводят к странным последствиям. SpeedyHeart обещала сделать видео-обзор всей найденой в процессе информации, так что ждем-с.

Чему меня научила эта ситуация? Не знаю. Я и так понимал, что использовать float для серьезных вычислений – идея сомнительная. Но теперь я лучше представляю, как именно все это будет работать на практике. Однако забавно получилось, что такая серьезная компания могла допустить такую серьезную ошибку, да еще и несколько лет подряд не замечать ее.

Мне кажется, что для данной задачи (подсчет IGT) нужно использовать такой путь: ставить timestamp в начале заезда, а потом вычитать из текущего времени. Причем арифметических операций стоит избегать, даже над целыми числами. 1/60 секунды это 16,(6) миллисекунд, поэтому в случае целого числа мы будем наивно откидывать 0,(6) при каждом сложении, что приведет к неточностям в подсчете.

В некоем обозримом будущем я постараюсь написать фикс и на другие версии. На этом у меня все, спасибо за внимание.

UPD: Поправил ссылку на гитхаб всвязи с переездом на новое имя.
UPD2: Выкатил вторую часть, интересующиеся могут прочитать.