서비스 초창기부터 소울워커는 최적화 문제에 시달려왔다.
최적화 문제로 여론이 나빠질 때마다 개발사에서는 “최적화를 위해 항상 노력하고 있지만, 구식 엔진의 한계로 인해 어렵다.”라는 주장만 되풀이하였고, 이번에 공개된 개발자 노트 또한 기존과 다를 바 없는 입장을 유지하고 있다는 것을 재확인시켜주었다.
그러나 현실에서 같은 엔진을 기반으로 한 게임이더라도 최적화 수준이 차이 나는 경우는 셀 수 없이 많으며, 이러한 게임들의 최적화 문제들은 엔진의 문제가 아닌 대부분 개발사의 문제인 경우가 많다.
특히 소울워커에서 최적화 하면 가장 먼저 떠오르는 로딩 속도 문제가 그렇다.
올해 초, GTA 온라인의 한 유저가 7년 동안 방치되어 있었던 버그를 게임사에 제보해 전체 플랫폼에서의 로딩 속도를 6분에서 1분 10초 정도로 약 70%가량 줄인 사례(https://nee.lv/2021/02/28/How-I-cut-GTA-Online-loading-times-by-70/) 가 있었다.
자그마치 7년이나 방치되었던 로딩 문제의 원인은 엉뚱하게도 서버에서 받아온 "10MB" 짜리 데이터 파일을 비효율적으로 분석하면서 일어난 일이었고, 원인이 되는 함수 2개를 후킹 해서 고치기까지 고작 138줄의 코드 밖에 필요하지 않았다.
다시 소울워커 이야기로 돌아와보자.
소울워커 또한 매우 긴 최초 로딩 시간문제로 많은 유저들이 고통받고 있다. 물론, 게임 규모가 크면 클수록 대체적으로 로딩이 길지만 소울워커의 경우는 전체 데이터 파일 크기가 10기가 정도밖에 되지 않는 데다가, 마을 <=> 던전 간 로딩이 항상 존재하며, 마을에서도 1초마다 다른 유저 캐릭터를 불러오느라 틱틱 끊기는 것은 이미 일상화되었다.
이런 상황에서 최초 로딩이 사양에 따라 최대 몇 분씩 걸리는 것은 상식적으로 전혀 납득이 되지 않는다.
그래서 해당 글에 나와있는 것처럼 직접 원인을 찾아보기로 했다.
이 지독한 로딩과 함께 5주년을 기념하지 않기 위해...
먼저 비교를 위해 정확한 로딩 시간 측정부터 진행했다.
1차: 1분 10초 44
2차: 1분 9초 68
3차: 1분 10초 31
= 평균: 1분 9초 14
CPU: AMD Ryzen 9 5950x
RAM: DDR4 16x4 (2666Mhz)
SSD: 970 EVO Plus 1TB
GPU: GTX 1050Ti
16코어 CPU와 초당 3GB를 읽어들이는 SSD도 1분의 벽을 넘지 못했다.
소울워커가 그렇게까지 고도의 연산과 I/O 능력이 필요한 게임이었던가?
더 자세히 알아보기 위해 작업 관리자로 게임 시작 시부터 리소스 사용량을 분석해 봤다.
이상하게도 처음 일정 구간까지는 CPU 사용량과 디스크 사용량이 증가하다가 그 이후부터는 게임을 시작하지 않은 것처럼 뚝 떨어지는 것을 볼 수 있었다.
이를 GTA의 사례와 비교해 보면 매우 이질적이라는 것을 알 수 있는데, GTA의 경우 잘못된 JSON 파서 구현으로 CPU 점유율이 급증하는 모습을 보였지만, 소울워커는 오히려 마치 아무것도 하지 않는 것처럼 잠잠했다.
아무것도 하지 않는 것 같으면서 실제로 로딩은 천천히 되고 있다니... 벌써부터 느낌이 쎄하다.
프로파일러를 돌려보니 아니나 다를까, 모듈 중 하나에서 ReadFile 시스템콜을 신나게 조져주시는 모습을 발견할 수 있었다.
다행히 해당 부분은 패킹된 실행 파일이 아닌 별도 모듈이 담당하고 있어 패치는 비교적 쉬워 보였다.
그런데 이렇게까지 ReadFile을 호출하는데 어떻게 디스크 사용량은 0%를 유지했던 걸까?
ProcessMonitor로 실제 게임이 로딩 시에 어떤 파일에 접근하는지 알아봤다.
그 결과는...
아......
최초 로딩 시에 일정 부분 디스크 사용량이 올라갔던 부분에서는 각 데이터 파일을 빠르게 읽었었고(해싱 과정으로 추정됨), 이후 디스크 사용량이 0%를 유지하면서 늘어졌던 부분에서는 데이터 파일을 1바이트씩 읽고 있었다.
게임 시작시부터 로딩이 완료될때까지 ReadFile이 호출된 횟수는 3600만번에 달했다.
조금 검색해 보니 소울워커의 데이터 파일은 암호화된 zip 형식이었다. 위키피디아에서 찾은 zip 헤더 구조와 ProcessMonitor에서 보인 ReadFile 패턴이 일치한 것을 보아, 맨 끝 -> 중간중간 읽기 패턴은 각각 ZIP 파일의 EOCD -> Central directory file header를 순서대로 읽는 과정임을 알 수 있었다.
문제는 이를 1바이트씩 읽어들였기 때문에 수십 개의 데이터 파일 중 파일 723개가 존재하는 data01.v 압축파일 하나를 파싱 하는데만 ReadFile을 48 + (30 + 1) + 723 * (46 + 1) = 34060번이나 호출해야 했고, 이를 메인 스레드에서 진행하는 바람에 파일을 1바이트씩 불러올 때마다 메인스레드 전체가 대기하는 "블로킹" 현상이 발생하였으며, 이 때문에 전체 로딩 시간이 길어졌던 것이었다.
디버거로 실제 게임에서 첫 4바이트를 읽는 부분을 추적했더니 이런 구조의 코드가 나왔다.
1바이트씩 총 4번을 읽어 byte_3부터 byte_0까지 저장하고, 이를 자릿수 별로 곱한 뒤 합쳐서 4바이트 정수로 만드는 과정이 포함되어 있다.
얼핏 보면 문제없어 보이는 코드지만, 사실 해당 코드는 다음과 같이 최적화할 수 있다.
x86(i686, x86-64 등) 기반 컴퓨터는 바이트 순서로 리틀 엔디언을 사용하기 때문에 한 번에 4바이트를 읽어도 실제 메모리에 저장되는 값은 기존 코드의 output과 동일하다. 따라서 기존 코드처럼 1바이트씩 읽고 시프트 연산으로 4바이트 정수를 만드는 과정을 할 필요 없이 그냥 output을 버퍼로 사용하고 그대로 읽으면 된다.
기존 함수를 후킹 하여 해당 내용을 적용했더니 정상적으로 ZIP 헤더를 4, 2바이트씩 끊어서 읽는 것을 확인할 수 있었다.
이제 각 헤더 크기별로 읽게 되었으니 이를 활용해 특정 시그니처가 인식될 경우 헤더의 고정 크기 사이즈만큼을 캐싱 하는 후킹 함수를 제작하기로 했다.
원리는 간단하다. 파일을 읽는 함수를 후킹 한 다음 캐시가 존재하지 않을 때 4바이트 읽기 요청이 오면, 기존 함수를 이용해 파일에서 4바이트를 읽고, ZIP 파일 헤더 시그네쳐와 일치하면 해당 헤더의 고정 크기만큼을 추가로 읽어둔 뒤, 다음 요청부터는 미리 읽어둔 내용을 보내주면 끝이다.
매우 간단한 기능이지만 기존에는 파일 723개가 존재하는 압축파일 하나를 파싱 하는데 디스크 접근을 3만 번 넘게 필요로 했다면, 해당 함수를 적용했을 때 1 + 1 + 1 + 723 * (1 + 1 + 1) = 2172회로 단순 계산만으로도 90% 이상 감소하는 것을 알 수 있다.
이제 이 2가지 패치를 모두 적용했을 때 실제로 어떻게 달라지는지 확인해 보자.
먼저 ReadFile 횟수는 3600만 회에서 260만 회로 92.7% 감소하였다.
로딩 시간은...
패치 전 평균: 1분 9초 14
패치 후 1차: 21초 51
패치 후 2차: 21초 26
패치 후 3차: 21초 40
= 패치 후 평균: 21초 39 (-69.06%)
CPU: AMD Ryzen 9 5950x
RAM: DDR4 16x4 (2666Mhz)
SSD: 970 EVO Plus 1TB
GPU: GTX 1050Ti
로딩 시간은 무려 70%나 감소해서 20초대를 찍었다.
디스크 탐색에 시간이 오래 걸리는 HDD 사용자들은 체감이 더욱 클 것으로 예상된다.
요약
- 소울워커 최초 로딩 시 과도하게 ReadFile을 호출하는 바람에 메인 스레드에 블로킹이 걸려 전체 로딩 시간이 길어졌다.
- 원인은 4, 2바이트 단위로 데이터를 읽는 함수의 구조적 결함과
- 캐싱을 전혀 하지 않은 자체 구현 ZIP 파서에 있었다.
소스코드는 여기서 확인할 수 있다.
https://github.com/CirnoV/SoulWorker_Booster_PoC
해당 소스코드를 컴파일해서 나온 dll을 인젝션하면 적용되지만 이러한 행위 자체가 이용약관 위반이기 때문에 추천하지 않는다.
이로써 소울워커 초창기부터 이어져왔던 로딩 속도 문제는 어느 정도 끝이 났다.
해당 문제의 원인을 파악하는 데는 간단한 프로파일링 한 번으로 충분했고, 문제가 되는 함수 3개를 고치는데 사용된 후킹 코드와 최적화 코드는 다 합쳐도 150줄을 채 넘지 않았다.
이 작업을 진행하면서 특히나 놀랐던 건 GTA 온라인의 사례와 무서울 정도로 비슷하다는 점이었다.
1. GTA는 약 7년, 소울워커는 약 5년 정도로 둘 다 오랜 시간 동안 방치되어 있었고
2. 간단한 프로파일링으로도 단번에 문제를 파악할 수 있었으며
3. 원인은 2~3개의 작은 함수 단위에서 발생하였고
4. 개발자 한 명이서 고치는데 하루도 안 걸릴 만큼 작지만 치명적인 결함이었다.
5. 심지어 로딩 시간 감소 폭도 비슷했다.
어떻게 몇 년 동안이나 이 문제를 몰랐을까?
이 글의 모티브가 된 글에서도 같은 의문을 던졌지만 결국 답을 얻지는 못했다.
다만, 한 가지 알아줬으면 하는 것은 항상 측정하는 것이 중요하다는 점이다.
내 주력 분야인 웹 분야에서는 페이지 로딩 시간이 5초를 넘어가면 이탈률이 38%를 넘어간다는 통계가 있다.
그렇게 때문에 웹 개발자들은 API를 최적화하고, 파일 크기를 줄이고, 분할하며, 여러 프로파일러를 통해 병목 현상을 파악해서 수정하는 등, 밀리초 단위라도 빠르게 페이지가 로딩 될 수 있도록 노력하고 있다.
웹과 게임은 분명히 다른 분야지만, 이러한 로딩 문제가 사용자 경험에 나쁜 영향을 줄 수 있다는 건 분명한 사실이다.
이번 사례 또한 단 한번이라도 프로파일러를 이용한 성능 측정을 진행했더라면 이렇게까지 방치되지 않았을 것이다.
---------------------------------------------------
떡상 시절에 잠깐 하다가 올해 7월에 복귀한지도 이제 5개월째가 되어간다.
여러 고비가 있었지만, 멋모르던 뉴비에서 직업별 레이드 딜량 1위까지 찍었던 입장에서 소울워커는 애증의 게임이 아닐 수 없다.
스팀 이전과 시즌 2 등 아직 넘어야 할 산이 많지만, 이 글로 개발사가 짐을 한 가지라도 덜 수 있었으면 하는 마음이다.
소울워커 시즌 2 정보&공략 모음
소울워커채널 완장 목록 및 신고 / 호출
