Showing Posts From

분석

로그 분석 - QA만 아는 게임의 속내

로그 분석 - QA만 아는 게임의 속내

오전 10시, 로그부터 열었다 출근했다. 책상에 앉자마자 로그 폴더를 열었다. 어제 밤 CBT 빌드에서 보스전 버그 리포트가 3건 올라왔다. "보스 체력이 안 깎여요", "스킬이 안 나가요", "갑자기 튕겨요". 기획자는 "재현이 안 돼요"라고 했다. 재현이 안 되면? 로그를 본다. 서버 로그 12GB, 클라이언트 로그 3.5GB. 압축 풀었다. 메모장으로는 못 열어서 로그 뷰어 켰다. 회사에서 자체 제작한 툴이다. 이거 없으면 일 못 한다. 유저 ID로 필터링. 버그 발생 시간대로 좁혔다. 14:23:47. 이 순간의 로그만 봤다. [14:23:47.123] BossAttack_Start [14:23:47.145] DamageCalc: Expected 15000, Result 0 [14:23:47.147] ERROR: DivideByZero in DefenseModifier찾았다. 방어력 계산식에서 0으로 나눴다. 특정 장비 조합일 때만 방어력이 0이 됐다. 그래서 재현이 안 됐던 거다.로그는 거짓말을 안 한다 QA 3년 하면서 배운 게 있다. 기획자는 틀릴 수 있다. 개발자도 틀릴 수 있다. 유저 리포트도 부정확할 수 있다. 근데 로그는 안 그렇다. 로그는 그 순간 게임 안에서 무슨 일이 일어났는지 정확히 기록한다. 타임스탬프, 함수 호출, 변수 값, 에러 메시지. 전부 다. "이 아이템 확률 이상한 것 같은데요?" 유저가 그렇게 말하면, 나는 로그를 본다. [Gacha_Result] ItemID: 1205, Probability: 0.5%, Roll: 0.00347 [Gacha_Result] ItemID: 1205, Probability: 0.5%, Roll: 0.00891 [Gacha_Result] ItemID: 1103, Probability: 3%, Roll: 0.01234100번 뽑았을 때 결과를 전부 로그에서 추출한다. 엑셀로 정리한다. 통계 내서 확률표와 대조한다. 정상이면 "확률은 정상입니다"라고 보고한다. 비정상이면? 개발자 불러서 난리 난다. 작년에 한 번 있었다. 신규 이벤트 가챠 확률이 표기와 다르게 설정됐다. 로그 분석으로 잡았다. 런칭 전에 고쳤다. 로그 안 봤으면 큰일 날 뻔했다. 클라이언트 로그 vs 서버 로그 둘 다 봐야 한다. 클라이언트 로그는 유저가 본 화면이다. 버튼 눌렀을 때, 스킬 사용했을 때, 에러 팝업 떴을 때. 유저 관점의 진실이다. 서버 로그는 실제로 처리된 결과다. 데미지 계산, 아이템 지급, 퀘스트 완료. 시스템 관점의 진실이다. 둘이 다를 때가 있다. 예를 들어 어제. "아이템을 받았는데 인벤토리에 없어요" 리포트가 있었다. 클라이언트 로그: [UI_Reward] ItemID: 3401, Count: 10, Display: OK화면에는 보상이 표시됐다. 서버 로그: [Inventory_Add] ItemID: 3401, Count: 10, Result: FULL인벤토리가 꽉 찼다. 서버는 지급 실패했다. 근데 클라이언트는 그걸 몰랐다. 그래서 화면에는 "받았습니다"가 떴다. 두 로그를 대조 안 하면 못 잡는다.로그 뷰어가 없으면 못 살아 텍스트 로그 12GB를 메모장으로 열면? 컴퓨터가 죽는다. 그래서 회사에서 자체 로그 뷰어를 만들었다. 선배 개발자가 만든 거다. QA팀 최고의 도구다. 기능:시간대 필터링 키워드 검색 로그 레벨 필터 (ERROR, WARNING, INFO) 유저 ID 추적 함수 호출 트리 통계 추출이게 없으면 하루에 1개 버그 분석한다. 이게 있으면 하루에 10개 분석한다. 특히 '유저 ID 추적' 기능이 미쳤다. 한 유저의 플레이를 처음부터 끝까지 시간 순으로 볼 수 있다. 영화 보듯이. 10:05:23 - 로그인 10:05:45 - 던전 입장 (ID: 2301) 10:08:12 - 보스전 시작 10:08:47 - 스킬 사용 (SkillID: 401) 10:08:48 - ERROR: NullReference in BuffSystem 10:08:48 - 클라이언트 크래시이 유저가 뭘 했는지 다 보인다. 버그 재현 조건을 찾는다. 지난주에 크래시 버그 있었다. 재현율 5%. 랜덤처럼 보였다. 로그 뷰어로 크래시 난 유저 50명 추적했다. 공통점 찾았다. 전부 '특정 버프를 3개 이상 받은 상태에서 특정 스킬을 쓸 때' 크래시 났다. 조건이 까다로워서 재현이 어려웠던 거다. 로그 없으면 못 잡았다. 에러 로그의 심각도 모든 에러가 똑같지 않다. 로그 보면 에러가 엄청 많다. 하루에 수천 개. 전부 리포트하면 개발자가 죽는다. 그래서 심각도를 판단한다. 크리티컬:크래시, 서버 다운, 데이터 손실 즉시 보고, 최우선 수정높음:핵심 기능 동작 안 함, 결제 오류, 진행 불가 당일 보고, 빠른 수정중간:일부 기능 오류, UI 버그, 밸런스 문제 다음 날 보고, 다음 패치낮음:텍스트 오타, 사소한 연출, 드문 경우 리스트업만, 여유 있을 때어제 본 로그: [ERROR] TextureLoadFailed: ui_icon_empty.png이건 낮음. 아이콘 하나 안 나오는 거다. 게임은 된다. [CRITICAL] DatabaseConnectionLost: Retry failed after 3 attempts이건 크리티컬. DB 연결 끊기면 게임 전체가 멈춘다. 심각도 판단을 잘못하면 큰일 난다. 작년에 신입이 크리티컬 버그를 '낮음'으로 분류했다. 런칭 직전에 터졌다. 3시간 지연됐다.로그로 보는 유저 행동 로그는 버그만 알려주지 않는다. 유저가 게임을 어떻게 플레이하는지도 보인다. 던전 클리어 로그를 보면:평균 클리어 시간 어느 구간에서 죽는지 어떤 스킬을 많이 쓰는지 어떤 몬스터가 킬 타임을 늘리는지이런 데이터를 정리해서 기획팀에 넘긴다. "보스 2페이즈에서 유저 50%가 죽습니다. 난이도 조정이 필요해 보입니다." 데이터로 말한다. 기획자가 "느낌상 괜찮은데?"라고 해도, 로그는 거짓말 안 한다. 작년에 신규 던전 테스트했다. 기획자는 "30분 컨텐츠"로 만들었다. 로그 분석 결과: 평균 클리어 타임 52분. 80명 테스터 중 30분 안에 깬 사람 5명. 나머지는 40분 이상. 기획자: "에이, 숙련되면 30분 될 거예요." 나: "로그상 3페이즈 보스 체력이 너무 높습니다. DPS 최대로 해도 35분은 걸립니다." 결국 체력 30% 감소. 평균 38분으로 줄었다. 그래도 길지만 기획 의도보단 가까워졌다. 런칭 전날 밤, 로그와의 전쟁 CBT 마지막 날. 오후 9시. "내일 오전 10시 정식 런칭입니다. 오늘 밤 안에 주요 버그 다 잡아야 합니다." QA팀 전원 야근. 개발자들도 대기. 나는 로그 분석 담당이다. 오후 9시부터 새벽 6시까지. 9시간 동안 로그만 봤다. 총 3개 빌드 나왔다. 빌드마다 테스트하고 로그 확인하고 버그 리포트하고. 새벽 2시쯤. 로그에서 이상한 패턴 발견했다. [Shop_Purchase] ItemID: 5001, Price: 1000, Result: SUCCESS [Inventory_Add] ItemID: 5001, Count: 1 [Shop_Purchase] ItemID: 5001, Price: 1000, Result: SUCCESS [Inventory_Add] ItemID: 5001, Count: 2아이템을 2번 샀다. 근데 재화는 1번만 차감됐다. 더블 클릭 버그다. 네트워크 딜레이 있을 때 빠르게 두 번 누르면 중복 결제된다. 돈은 한 번만 나간다. 이거 런칭하면? 유저가 악용한다. 과금 아이템이면 회사 손해다. 즉시 보고. 크리티컬 버그. 개발자가 30분 만에 고쳤다. 다음 빌드에서 확인했다. [Shop_Purchase] ItemID: 5001, Price: 1000, Result: SUCCESS [Shop_Purchase] ItemID: 5001, Price: 1000, Result: LOCKED두 번째 요청은 막혔다. 정상. 새벽 6시. 최종 빌드 통과. 집에 갔다. 오전 10시 런칭. 나는 집에서 잤다. 로그 덕분에 큰 사고는 없었다. 로그 분석이 어려운 이유 로그 보는 게 쉬워 보이지만, 실제론 어렵다. 1. 양이 너무 많다 하루 로그가 수십 GB다. 런칭 후엔 테라바이트 단위다. 필요한 정보만 찾아야 한다. 검색 키워드를 잘못 잡으면 헛수고다. 2. 맥락을 알아야 한다 로그 한 줄만 보면 이해 안 된다. [BuffExpired] BuffID: 203이게 뭔지 알려면 기획서를 봐야 한다. BuffID 203이 뭔지, 만료되면 뭐가 문제인지. 게임 시스템을 다 알아야 로그를 읽을 수 있다. 3. 타이밍이 중요하다 버그가 10:30:45에 발생했다. 근데 원인은 10:28:12에 있다. 2분 전 로그를 봐야 원인을 찾는다. 언제부터 봐야 할지 감을 잡는 게 어렵다. 4. 서버와 클라이언트의 시간차 클라이언트 시간: 10:30:45.123 서버 시간: 10:30:45.567 0.4초 차이. 이게 순서를 헷갈리게 한다. "클라이언트가 먼저 요청했는데 서버가 나중에 받았네?" 이런 일이 생긴다. 5. 로그가 안 찍힐 때 제일 최악이다. 크래시가 나면? 로그 파일이 저장 안 될 때가 있다. 서버가 죽으면? 마지막 몇 초 로그가 날아간다. 로그가 없으면 분석을 못 한다. 재현할 수밖에 없다. 로그 분석하면서 배운 것들 게임은 생각보다 복잡하다 유저가 보는 건 화면뿐이다. 버튼 누르면 뭔가 된다. 근데 로그를 보면? 뒤에서 50개 함수가 호출된다. 10개 서버와 통신한다. 100개 변수가 바뀐다. 간단해 보이는 액션 하나에 엄청난 처리가 숨어있다. 숫자는 거짓말 안 한다 "이 던전 쉬운 것 같은데요?" 로그: 평균 사망 횟수 4.7회 "이 확률 높은 것 같은데요?" 로그: 실제 확률 0.3% 느낌이 아니라 데이터로 본다. 버그는 항상 조건이 있다 "가끔 튕겨요" 리포트. 가끔이 아니다. 특정 조건에서 100% 튕긴다. 조건을 모르면 가끔처럼 보일 뿐이다. 로그를 보면 조건이 보인다. 오후 7시, 오늘도 로그를 닫았다 퇴근 시간이다. 오늘 본 로그: 8.5GB 찾은 버그: 7개 작성한 리포트: 7건 마신 커피: 4잔 내일도 로그를 볼 거다. 출근하면 제일 먼저 로그 폴더를 열 거다. 게임 QA는 게임하는 직업이 아니다. 숫자 읽는 직업이다. 로그로 게임의 진실을 읽는다. 유저는 모르는, 개발자도 놓친, 게임 안의 숨겨진 이야기들. 오늘도 로그 덕분에 하나 잡았다. 내일은 뭐가 나올까. 로그 뷰어를 닫았다. 모니터가 어두워졌다. 집에 가서도 게임할 거다. 근데 이제는 로그가 보인다. 화면 뒤의 숫자들이. 이게 직업병인가.로그는 게임의 블랙박스다. 사고 나면 제일 먼저 확인하는 거.