Не так давно, на заре этого тысячелетия, холодным ноябрьским днем 2004го я сел писать эмулятор сервера для некой онлайн игры. Писалось мне весьма хорошо, на радующем глаз C# и .Net Framework версии 1.1. Особых целей перед собой я не ставил, а опыт имел сравнительно небольшой. По какой-то причине сообщество оценило эту поделку (может, потому что она появилась раньше официального старта основной игры?) и через несколько месяцев я столкнулся с взрывным ростом онлайна, а заодно и серьезными проблемами производительности. Проект прожил 6+ лет, достиг заметных высот (2500 онлайна в пике, порядка 20000 MAU), а затем и почил в бозе. И вот спустя полтора десятилетия я решил сделать собственную ММО игру на тех же “проверенных временем” наработках и столкнулся с аналогичными же проблемами, не смотря на то, что они были уже единожды мною решены.

P.S. При написании этой статьи не пострадала ни одна IP, изначальный проект хоть и был пропитан духом пиратства (бесплатный сервер платной игры!), никаких прав не нарушал, код правообладателя там не использовался, а сервер базировался целиком на исследованиях честно купленного клиента игры и здравом смысле разработчика. Данный опус рассказывает только о вызовах, с которыми столкнулся автор и оригинальными методами их решения, как в старом, так и в современном проекте. Я заранее прошу прощения за повествовательный стиль рассказа, в противовес простому перечислению фактов.

Вступление


Можно сколько угодно спорить о том, что .Net не для серверов, но мне тогда (да и сейчас) показалось весьма здравой идеей, что можно писать логику в виде скриптов, компилировать и подгружать её на ходу, не сильно думая о выделении памяти, сборке мусора, указателях и прочем. По-сути, это позволяет делегировать скриптование бизнес-логики менее квалифицированным разработчикам, ограничиваясь только Code Review. Но для этого надо убедиться, что само ядро работает без сбоев, а оно начинало сбоить уже при 10-15 онлайна, как в 2004-м, так и в 2020-м.
В 2004-м все крутилось на Windows Server 2003, .Net 1.1, MSSQL 2000. Сервер и хостинг предоставил провайдер Wnet, а затем и был собран новый сервер на пожертвования игроков. Проект был сугубо не коммерческий, а некоторый минимальный доход от баннеров и премиум аккаунтов был пущен на апгрейды.
Современный сервер работает на Mono под Debian в режиме совместимости с .Net 4.7, с MariaDB для данных, размещается в облаке Hetzner. Давно уже нет того идеалиста с горящими глазами, который верил, что игры должны быть бесплатными, а донат и продажа игровых вещей убивают весь интерес. Сейчас этот персонаж изрядно поседел, сменил задор на опыт и убеждён, что стартап должен приносить как удовольствие, так и доход.

Но сказ не об этом, а о самописных серверах и их проблемах.

Глава 1. Мор



На локальном компьютере и с одним игроком сервер всегда работал идеально. На выделенном же компьютере и живых игроках, иногда процесс сервера банально закрывался, особенно тяготея к ночным падениям, когда админы спят. Забавно было, когда пользователи звонили в службу поддержки провайдера, те передёргивали питание сервера и на утро причину установить уже было невозможно. Сервер работал как сервис, поэтому перезапускался без проблем, а в логах явных причин падения видно не было. Я несколько раз пробовал запускать процесс из Visual Studio, но дебаггер отваливался через какое-то время, да и производительность сильно страдала. Системный же EventLog оказался удивительно не информативным.

В первую очередь я решил существенно улучшить систему логирования — она стал перехватывать все, что попадало в Console.Out и Console.Error. Затем был добавлен обработчик UnhandledExceptionHandler, который тоже писал в лог информацию об ошибках. Лог умел работать в режиме AutoFlush = true, что добавляло тормозов, но защищало от оборванных на середине фраз.

Следующим шагом была переделка сервиса в режим консольной программы и запуск из отдельного окна cmd — так можно было найти это окно и попытаться в нем прочитать последнее, что пытался нам сообщить сервер. Это, кстати, привело к потрясающей проблеме, когда сервер останавливался из-за клика мышью в консольное окно — включался режим выбора текста, останавливавший процесс. На каком-то этапе я писал сразу два лога — через .Net и перенаправлением в >> log.txt.

К сожалению UnhandledExceptionHandler не помогает с тремя видами исключений: OutOfMemoryException (любое действие в обработчике может потребовать выделения памяти и не будет выполнено), StackOverflowException и исключениям в Unmanaged коде. И как оказалось, у меня были как минимум два из них — Access Violation где-то в нативном коде и OOM.
Для борьбы с Access Violation я собрался с силами и полностью избавился от нативного кода — никакого больше ZLib (заменен на ICSharpCode.SharpZipLib), никакого OpenSSL (написана собственная реализация SRP-6), никакого нативного MySQL коннектора (выполнен переход на System.Data и MSSQL для БД).

Отдельно обнаружилось, что выброс исключения в коллбеке от Socket.BeginReceive может заморить весь процесс целиком. Этот коллбек выполняется в .Net Thread Pool (в той части потоков, что зарезервированы для IO Threads) и в случае выброса исключения рушит всю программу, не смотря на UnhandledExceptionHandler. Ну и чуть позже оказалось, что цепочка вызовов BeginReceive->EndReceive->BeginReceive тоже вызывает проблемы и ее надо дорабатывать, чтобы BeginReceive не вызывался из колбека.
Все это существенно улучшило картину и сервер стал падать гораздо реже, в основном лишь когда заканчивалась память.
В 2020-м приложение сервера было в принципе только консольным, запущенным в отдельном screen в Linux. Вариантов запуска под Visual Studio более не было, зато логгер с годами стал весьма продвинутым, UnhandledExceptions попадались как зайчики в сети, а нативного кода не было в принципе. Что, правда, не спасло от падений с OOM и StackOverflowException. Глубина стека в случае StackOverflowException выросла в десятки раз, забивая сотни килобайт лога однотипными сообщениями и отказываясь писать нормальный стек трейс. Но в любом случае перенаправление в >> log.txt быстро позволило понять, кто и где виноват. Отдельно помог Телеграм бот, который сигнализировал, что процесс сервера умер.

Дальше было только дело техники. Изучение логов показало, что переполнение стека как раз проявилось не в ядре, а в бизнес-логике: ракета сталкивалась с другой ракетой или миной, те детонировали, это запускало детонацию первой ракеты и так по кругу. В целом, это обычный рабочий момент, но именно тогда я почувствовал странное дежавю, борясь с давно забытыми демонами прошлого. А затем проявилась новая (или давно забытая старая) причина мора — нехватка ресурсов.

Глава 2. Глад



Сервера в начале века могли иметь невероятное количество памяти — на домашнем компьютере я довольствовался 256 Мб ОЗУ, а на сервере был целый гигабайт! И все-равно этой памяти не хватало, она медленно, но неуклонно съедалась, она утекала как вода и с повышением онлайна счет до падения уже шел не на дни, а на часы — каждый раз запуская сервер я с ужасом ждал, когда нехватка ресурсов вызовет OOM или что-то еще похлеще. Конечно, я не сидел сложа руки — неоднократно пытался подключиться к работающему серверу с Visual Studio (при нехватке памяти это превращалось в пытку, а затем в падение), пытался делать дамп памяти через утилиты WinDbg (неуспешно), один раз умудрился запустить сервер из-под dotTrace (ненадолго). Хорошим решением стала установка еще одной планки памяти на гигабайт, а затем и вынос БД на отдельный компьютер. Но проблема оставалась — память сервера медленно, но уверенно подходила к планке 1.7Гб, после чего происходил краш. Настройки файла подкачки не помогали. Отдельно все чаще я стал замечать загрузку процессора в 100%. Сервер откровенно голодал, ему не хватало ресурсов, но я не мог понять, почему — даже на моем домашнем компьютере за несколько часов работы он не выбивался из разумных ~100 мегабайт. Настоящим откровением стали статьи Maoni Stephens и Rico Mariani про GC, дурацкое слово LOH (Large Object Heap) и организацию памяти в .Net. Как казалось, все сетевые операции фиксировали (pin) буферы в памяти, что автоматически отправляло их в Gen 2, а в случае крупных размеров — прямиком в LOH, особый круг преисподней для самых толстых больших объектов. Я боролся с ними как молодой Давид — писал собственные пулы для буферов, переиспользовал массивы как мог, реализовал собственные коллекции, которые для работы брали массивы из пула и потом возвращали их туда (напомню, это в .Net 1.1 без Generics!). Но Голиаф крепко стоял на ногах — память хоть и чуть медленнее, но все-таки утекала, голод не отступал. Тогда я собрался с силами и стал выделять буферы через Marshal.AllocHGlobal в куче и сам следил за их удалением (которое происходило почему-то заметно реже, чем создание). Уже было ясно, что утекают именно эти буферы, используемые в отсылке и получении данных по сети. Медленно, но уверенно я искал причину, постепенно начиная подозревать, что загрузка в 100% CPU тоже как-то к этому причастна. В очередной отчаянной попытке я сделал Interop вызовы напрямую к WSASend/WSAReceive (работа с сетью в Windows напрямую, минуя .Net) и в этот момент утечки памяти нормализовались. Это было очень-очень странно, я несколько раз возвращался к родной .Net версии сокетов и каждый раз ситуация повторялась: вызовы BeginSend/BeginReceive не всегда корректно завершались соответствующими коллбеками, не всегда потоки отдавались назад в пул, а это иногда сопровождалось еще и 100% загрузкой CPU.

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

И вот, в начале лета 2005го года я прочитал статью про Workstation GC и Server GC и ради них запустил сервер на .Net 2.0 Preview. И это был долгожданный прорыв — все вызовы асинхронных методов стали корректно завершаться, а посторонняя нагрузка сконцентрировалась в отдельном GC потоке, который потреблял 5-10% CPU.

У меня было время и настроение, поэтому я провел десяток экспериментов и точно мог сказать, что вызов сборщика мусора в потоке от Thread Pool в Net 1.1 и Workstation GC мог привести к глухому зависанию этого потока, еще даже до выполнения самого кода вызываемого метода (привет не возврат буфера в пул или кучу!) или иногда после него (привет 100% загрузки).
Со временем я окончательно отказался от BeginSend/BeginReceive и использовал исключительно Windows IOCP для всех операций с сетью. Сервер уже был полностью многопоточным и соединения обрабатывались параллельно, что было весьма хорошо и прогрессивно, не смотря на большое количество блокировок, которые раньше были толком не видны на фоне OOM или 100% жора процессора.
Современный сервер с объемами менее 4Гб памяти вызывает ухмылку, а добавить для облачного решения лишние 8-16 гигабайт можно в пару кликов и один рестарт. Тем не менее, когда начала утекать память и загрузка процессора подскочила до 100-150% (из расчета 800% на 8 ядер), я снова почувствовал себя 20-летним студентом, сжигающим гигабайты и гигафлопсы в топке прожорливой машины. Это было странно, не нормально и глупо. Особенно неприятно было, что как и раньше игра продолжала идти нормально (пусть и с лагами), но ничего не прерывалось. Ну, пока не заканчивалась память, конечно.

За эти годы успели появиться и исчезнуть Lightweight Threads (они же Fibers) из-за которых мы больше не имеем доступа к системным потокам в .Net, только к т.н. Managed Threads, а на Mono еще и нет доступа к ProcessThread — внутри одни только заглушки. Диагностика потоков существенно усложнилась, но зато я теперь использовал собственный Thread Pool, все потоки были просчитаны и именованы, для каждого велась точная статистика, какой из них что сейчас выполняет, сколько времени занимает конкретная задача. За счёт этого довольно быстро получилось отследить, что сейчас неполадки именно в моем коде, а не в системном, а статистика потоков показала, что жор связан с выполнением бизнес логики, просто некоторые действия выполняются в 100 раз чаще, чем должны. Сейчас я не был ограничен в ресурсах, поэтому совершенно спокойно снабдил вызов каждого скрипта и таймера дополнительным логированием, замерил время выполнения каждого события и за неделю экспериментов смог уверенно сказать в чем проблема. Оказалось, что некий NPC пытался атаковать другого NPC и оба были застрявшими в камнях, поэтому не могли двигаться и их попытки стрельбы друг в друга моментально прерывались из-за отсутствия Line Of Sight. Но при этом каждый такт расчета поведения (15мс) они пытались просчитывать путь, начинали стрелять, но из-за невозможности выстрела у орудий не шла перезарядка и на следующий такт все повторялось. За несколько дней игры таких NPC набирались сотни и они в итоге съедали все ресурсы сервера. Решением стала правка поведения и уменьшение ситуаций с застреванием, а заодно небольшое время перезарядки даже для неудачных выстрелов.

А затем сервер стал зависать.

Глава 3. Хлад



Осень 2005 года выдалась не простой — у меня была неопределенная ситуация с работой, аренда квартиры неожиданно удвоилась. Радовал только игровой сервер — онлайн уже исчислялся сотнями, но и там началась проблема — весь мир начал замирать. В лучшем случае продолжали ходить пинги или работать некоторые таймеры. А иногда и замерзало вообще все, прекращался трафик и приходилось убивать приложение сервера и запускать снова. Как и прежде, невозможно было подключиться отладчиком к работающему серверу из-за существенного потребления и тормозов. По каким-то причинам Visual Studio от этого просто падал, либо зависал.

С каждым днем проблема становилась все более серьезной — сотни человек онлайна невероятно расстраивались, что не могут поиграть и грозились уйти. Админов все так же тяжело было убедить, чтобы они оставляли зависший сервер и давали мне возможность что-то с ним сделать. Но проблема была в том, что и сделать-то я ничего не мог. Неопределенное время было потрачено на борьбу с SOS.dll. Эта замечательная библиотека с именем Son Of Strike должна работать как модуль к WinDbg и может показать .Net потоки, задачи, место выброса исключения и другие полезные вещи. Все бы хорошо, но библиотека очень чувствительна к версии .Net и типу GC. И по какой-то дурацкой причине именно конкретно для моей ��ерсии подсоединение sos.dll срабатывало один раз из 50. То версия не та, то подключились, но работать не можем, то Марс ретроградный. Буквально лишь один раз у меня получилось увидеть стену текста и цифр, из которой я вынес одно — у нас deadlock!

Честно говоря, я был не готов к этому. Диагноз звучал как приговор — наличие перекрестных блокировок это явное следствие плохой архитектуры. И дальше самокопание и депрессия по накатанной — опыта было мало, литературу не читал и ввязался в непонятно что, нет чтобы сайтики рисовать, а в выходные пиво пить, он в сервера полез! С трудом скинув наваждение я начал думать, гуглить и искать варианты. В первую очередь я нашел варианты использовать самописные SpinLock и try/finally для их вызова. Это не защищает напрямую от перекрестных блокировок, но оригинально позволяет определить, кто виноват — потоки, ждущие SpinLock не останавливаются, а явно потребляют процессор, поэтому взгляд на список потоков и последнюю вызванную задачу должен, по идее, показать, кто на чем застрял. В моем случае застревало сразу штук 8 потоков, поэтому пользы от этого не было. Однако, я попробовал решить вопрос административным путем: раз я уже перешел на собственные классы для блокировок, то я их расширил и для каждого потока вел отдельный счетчик, чтобы знать глубину “кроличьей норы”. В итоге вообще все места, где использовалось две и более блокировок я переписал начисто. Это заняло около полугода, такие проблемы встречались повсеместно, но результат того стоил — до самого закрытия сервера дедлоков больше не было.

А дальше изменилась и ситуация с жильем, работой, а еще силами игроков мы купили новый сервер с Xeon 5130x2 и 8Гб памяти. Онлайн рос до 2000, а затем кратковременно поднялся и до 2500, но потом стал спадать. Игроков уже не устраивало, что сервер работает стабильно, им нужны были возможности, скрипты, таланты и прочая бизнес-логика, с которой я не успевал справляться с должной скоростью и с надлежащим качеством. Но это уже совсем другая история.
В один из холодных октябрьских дней 2020-го запланированный приход лайв стримеров сорвался, потому что сервер неожиданно завис. Работала авторизация, но нельзя было зайти в мир, Телеграм-бот молчал. Быстрый поиск проблем не показал ничего в логах, не было проблем с памятью, ни один из потоков не голодал. Просто все остановилось. Произнеся вслух несколько раз что-то там про кота из матрицы и женщину непристойного поведения я полез искать дедлок. После покупки Майкрософтом Мигеля де Икаса и Xamarin документация по Mono представляет собой жалкое зрелище — она как бы есть, но не актуальна, либо никуда не ведет. Например, 3/4 данных со страницы про отладку в mono с gdb не применимы и не работают. Я смог подключиться к замерзшему серверу через gdb, но команды call mono_pmip и другие давали невразумительные ответы, в основном про синтаксические ошибки. Каким-то чудом я понял, что gdb хочет, чтобы я приводил параметры и результат команд mono_* к определенным типам и так я в итоге смог получить список потоков, замерших в перекрестной блокировке. Но номера в списке не соответствовали ни результатам команды ps, ни ManagedThreadId из сервера. Существенно помогло расширенное логирование, которое я делал для поиска жора процессора — по нему я смог понять, какие пакеты и таймеры выполнялись последними и понемногу стал сужать круг подозреваемых. Как на зло, перекрестная блокировка была не с двумя потоками, а с тремя, поэтому более детальной картины получить не удавалось. Тогда я вспомнил о старых граблях и стал просматривать код на использование блокировок. Как оказалось, за эти годы прошло несколько рефакторингов и SpinLock понемногу заменились на Monitor.Enter/Monitor.Exit, а часто и на простой lock. И тут неожиданно на глаза мне попалась статья Eric Gunnerson, в которой говорится, что можно же делать в разы проще: использовать везде Monitor.TryEnter с таймаутом и если блокировку сделать не удалось, то бросать исключение. Это невероятно простой и очень действенный метод — если где-то вызов TryEnter прождал более 30 секунд и выпал (а логике такие задержки не свойственны), то это место обязательно надо исследовать и проверить, кто мог так надолго забрать себе и не отдать объект блокировки. Посыпая голову пеплом я осознал, что мог и 15 лет назад таким образом все вычистить, не обязательно было изобретать велосипед с подсчетом “глубины норы”. Но может тогда это было и к лучшему.

Ну а потом к новому проекту, как когда-то и к эмулятору, пришел 4й всадник. Только популярным он стать не успел. Все-таки наличие аж трех критичных проблем прямо на старте проекта его быстро подкосили. Да и игра вышла совсем не мейнстримовой. Но это тоже тема не для этой статьи.

P.P.S. В статье использованы иллюстрации неизвестного художника Parsakoira с подписью “ChoW#227 :: VOTING :: 4 Horsemen of the Apocalypse”, предположительно с умершего уже сайта conceptart.com:
https://www.pinterest.com/pin/460141286926583086/
https://www.pinterest.com/pin/490681321879914768/