30.11.2020 07:22
Nomad1 26 8800 Источник
Не так давно, на заре этого тысячелетия, холодным ноябрьским днем 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/