2013년의 어느날 디버깅 메모(windbg)

게시일: megayuchi님이 작성

2013년 12월 27일 , Project D Online 출시 준비할때였다.
첫번째 보스(벽에서 미사일 쏘는 보스-혼두라 모티브)랑 싸우고 나오면 나와서 맵체인지 할때 게임이 멈추는 증상이 있었다. 멈춘다고 하는것은 플레이어 입장이고 정확하게 얘기하자면 데드락 아니면 무한루프인데 이 경우는 데드락이었다. 데드락은 데드락인데 그게 어플리케이션이 사실상 크래시한거고 크래시에 의한 데드락이었다.
버그 재현도 잘 되지 않아서 엄청나게 절망했었다.
최초 같은 사무실에 있던 K군의 자리에서 이 버그가 나타났고 일단 덤프는 떠놨던걸로 기억한다. 그 덤프 가지고 분석해서 원인을 찾았고 이후에 버그를 100% 재현할 수 있었다.
windbg로 분석하다가 windbg스크립트까지 써서 겨우 잡았던 버그였다. 기특하게도 원노트에 당시 작성했던 스크립트와 버그 증상-원인을 적어놨었다.
3년전에 페북에 짤막하게 써놨는데 오늘 3년전 오늘이라고 떠서 생각이 났다.
당시의 버그 증상과 원인, 사용했던 windbg스크립트를 원노트에 적어둔게 있어서 기록 차원에서 블로그에 남겨둔다.

이하 원노트에 적어뒀던 버그 증상-원인
——————————————————————————–

[F101보스 던전에서 보스 잡고 나와서 맵체인지 완료할때 무한루프에 빠짐]

콜스택은 다음과 같다.
OnRecvPlayerWarpMap
+ChangeSceneToBattleField
++Run()
+++BeginCollisionTest()
++++UpdateGrid()
+++++InsertToCell()

직접 크래시 원인은 어떤 Ellipsoid가 가지고있는 SpaceIndex가 가리키는 CSpace 포인터테이블의 값이 NULL이기 때문.
CollisionManager안에서 m_ppSpaceList[SpaceIndex]가 NULL이다.

  1. F101맵 건물 지하에서 보스 잡으러 보스던전으로 들어간다.
  2. 보스 던전 바닥을 잘 보면 실외공간을 정의하는 박스때문에 뻥 뚫린 공간이 보인다.
  3. 이 공간은 SolidBSP로 공간이 아닌 영역이다.
  4. 보스가 로켓을 쏜다. 그러다가 그 로켓중 한발이 이 박스 안쪽의 영역으로 들어간다.
  5. 이 경우 Scenegraph핸들이 -1이 된다. 유효하지 않은 영역이기 때문이다.
  6. CDynamicObjectManager::ThrowCharacterObjectToRecycleBin()함수 안에서 오브젝트를 사실상 지워진것으로 간주하고 충돌타원체를 해제해야한다.
  7. 그런게 버그 발생 당시 코드를 보면 ThrowCharacterObjectToRecycleBin()함수 안에서 충돌처리 타원체를 해제하는 코드가 없다. 정확히는 CSceneGraph::DeleteObject()함수만 호출하는데 이 안에서 m_dwSceneGraphHandle이 -1이 아닌 경우에만 CCharacterObject::DeleteCollision()을 호출한다.
  8. 서버에선 RecycleBin을 사용하지 않지만 클라이언트에선 로켓에 대해서 RecycleBin을 사용하고 있다.
  9. 로켓이 예의 박스 영역에 들어가면 m_dwSceheGraphHandle = -1이 된다. 또한 바닥에 깔려있는 박스이므로 로켓은 파괴될 것이다.
  10. FreeRocket()에 의해서 로켓은 해제되나 정책에 의해 RecycleBin에 들어간다. 따라서 ThrowCharacterObjectToRecycleBin()함수가 호출된다.
  11. m_dwSceneGraphHandle == -1이므로 CSceneGraph::DeleteObject()를 호출하지 않는다. 따라서 DeleteCollision()함수도 호출하지 않는다.
  12. 보스를 잡고 보스 던전에서 나온다. 보스 던전은 메모리에서 제거된다. SuicaCollision DLL에서 보스던전에 m_ppSpaceList[SpaceIndex] = NULL이 된다.
  13. 해제되지 않은 타원체의 SpaceIndex는 NULL로 세팅된 CSpace포인터를 가리키게 된다.
  14. m_pGeometry->BeginCollision()이 호출되면 SuicaCollision DLL안의 모든 타원체에 대해 위치를 갱신한다.
  15. 해제되지 않은 타원체가 가리키는 CSpace포인터는 NULL이다. -> 크래시한다.
  16. 크래시 후에 문제는 익셉션 핸들러로 넘어간다.
    1. DEV버전이므로 풀덤프를 시도하고 그 전에 풀덤프를 저장한다는 메시지 박스를 띄운다.
    2. 그런데 메시지를 펌핑해야할 메인스레드는 충돌처리 엔진의 스레드들이 모두 완료하기를 대기하고 있다.
    3. 일반적인 흐름에서는 APC이므로 메인스레드가 메시지 펌핑을 할 수 있다.그러나 WaitFor…()함수에서 대기하고 있으므로 APC수행 불가능.
    4. 메시지 박스에서 OK가 떨어지지 않으므로 충돌처리 스레드도 덤프저장으로 가지 못하고 계속 Wait
    5. 데드락 

정말 고생했다. 결국 밝혀내고 나면 원인은 별거 아니다. 늘 그러하듯. windbg를 이용해서 버그를 잡았고 해당 내용에 대해서 페이스북에 짧게 적어놨다.
이하 페이스북에 적은 내용
——————————————————————————–
몇 시간 동안 디버깅한 끝에 처음의 가설이 반은 맞고 반은 틀렸다는걸 확인했다.
캐릭터 오브젝트중에 해제가 안된게 있는건지, 캐릭터 오브젝트는 모두 해제했는데 그 중에 충돌타원체를 해제안하고 소멸한 놈이 있는건지…
이걸 확인하려면 메모리상에 존재하는 캐릭터 오브젝트들을 싹 긁어서 유효한 타원체 핸들을 가지고 있는 놈을 찾아야한다.
release빌드의 풀덤프인데 일단 덤프를 뜬 머신과 빌드한 머신의 타임스탬프가 달라서 VS디버거에선 심볼이 제대로 나오지 않고있다.
일단 windbg로 풀덤프를 읽어서 캐릭터 오브젝트의 링크드 리스트 첫번째 항목의 어드레스까진 찾아냈다.
여기서부터 주소를 따라가며 오브젝트의 내용을 확인해야하는데 IDE로 하나하나 찾자니 시간이 너무 걸렸다.
링크드 리스트를 따라가면서 캐릭터 오브젝트의 포인터를 찾고 다시 타원체의 인덱스를 확인해야하는데 오브젝트 한개 확인하는데 대략 몇분이나 이상 걸리는 상황.
아 절망이다. 버그 재현도 안되는데.
혹시나 했는데 검색해보니 windbg에 스크립트 기능이 있었다.
이걸 지금 학습하자니 좀 막막했다. 5분동안 모니터를 쳐자보며 고민했다. 그냥 179개를 하나하나 노가다로 추적해볼까.
결국 스크립트를 사용하기로 결정. 열심히 구글링해서 필요한 기능만 찾아서 스크립트를 작성했다.
스크립트를 돌려보니 179개 오브젝트중에 타원체 인덱스가 -1이 아닌 캐릭터 오브젝트는 1개. 플레이어의 캐릭터니까 얘는 정상. 할당된 충돌타원체의 개수는 2개. 1개가 고아로 남아있는거네.
결과적으로 보스가 쏜 로켓탄이 자신의 충돌처리용 타원체를 해제하지 않고 소멸한 것으로 확인. 뭐 이제부터 또 다른 국면이긴 하지만.
일단 버그의 범위를 확 좁혔다.이제부터는 코드를 좀 뒤져봐야겠다.
이거 노가다로 확인했으면 아직까지도 못찾았을듯. 결과를 확신할수도 없고.
windbg script상당히 쓸만하네. 앞으로의 디버깅에도 엄청 도움되겠다.
——————————————————————————–

페북에는 스크립트 스크린샷을 이미지로 올려놨는데 원노트 찾아보니 당시 만들었던 스크립트도 적어놨더라. 이 역시 기록차원에서 적어둔다.

Windbg script
Ex) CDynamicObjectManager에서 현재 CharacterObject Link를 순회하고 그 중에 m_dwEllipIndex가 -1이 아닌 놈을 찾아낸다.

((CDynamicObjectManager*)0x00000000`218c7db0)

dt CSceneGraph 0x0000000017ece3d0
dt CDynamicObjectManager 0x00000000218c7db0

$$><d:\windbg.wds

$$ dump CCharacter CDynamicObjectManager::m_pCharacterLinkHead
.block
{
r $t1 = 0x000000001eb51160
r $t10 = 0
r $t11 = 0
.while(@$t1 != 0)
{
$$ t2 = CCharacterObject
r $t2 = poi(@$t1+0x010)

$$ t3 = CCharacterObject::m_dwEillipIndex
r $t3 = poi(@$t2+0x42c)

.if (poi(@$t2+0x42c) != -1)
{
dt CCharacterObject @$t2

$$sum selected Objects
r $t11 = @$t11 + 1
}
$$ sum total objects
r $t10 = @$t10 + 1

$$ next object...
r $t1 = poi(@$t1+0x008)
}
.printf "Selected CCharacter Counts : %p \n", @$t11
.printf "Total CCharacter Counts : %p \n", @$t10

}

근데 지금은 스크립트 다 까먹었다ㅠㅠ
다음에 디버깅할 일 있으면 이 문서를 보고 기억을 떠올려야지.

댓글 남기기