멀티쓰레드 서버 버그잡기

멀티 쓰레드 버그잡기

---

1. LockOrderChecker

void LockOrderChecker::Pop(FastSpinlock* lock)
{
 
	/// 최소한 락이 잡혀 있는 상태여야 할 것이고
	CRASH_ASSERT(mStackTopPos > 0);
	
	/// 당연히 최근에 push했던 녀석이랑 같아야겠지..
	CRASH_ASSERT(mLockStack[mStackTopPos - 1] == lock);
 
	mLockStack[--mStackTopPos] = nullptr;
 
}

버그 메시지는 여기서부터 시작한다. Lock Stack의 top과 pop할 대상 lock이 다르다! 이 스택은 LockOrderChecker에서 LockHierachy 유지를 위해서 사용하던 스택이다. 스택하면 생각나는 버그는 ABA이다. 하지만 LockOrderChecker는 TLS에 따로 저장된 객체더라. 쓰레드 별로 저장해 놨기 때문에 쓰레드 세이프할것같은데... 그렇다면 LockOrderChecker의 논리적 일관성은 보장 될 것이고 용의자 명단에서 제거할 수 있다.

2. FastSpinLock

void FastSpinlock::LeaveWriteLock()
{
	InterlockedAdd(&mLockFlag, -LF_WRITE_FLAG);

	/// 락 순서 신경 안써도 되는 경우는 그냥 패스
	if (mLockOrder != LO_DONT_CARE)
		LLockOrderChecker->Pop(this);
}

LockOrderChecker의 push/pop 호출부는 FastSpinLock의 EnterLock/LeaveLock에서만 호출된다. 이때 lock 스택에 저장되는 것이 this 즉 이 SpinLock이다. LockOrderChecker에는 문제가 없다. 그렇다면 SpinLock에서 잘못된 값을 push/ pop 했기 때문에 문제가 발생했다고 생각할 수 밖에 없다. 여기서도 lock의 flag를 atomic 연산을 통해서 안전하게 변경시키고 단순히 this를 넘기기만 한다. 따라서 별로 문제가 발생할 부분이 보이지 않는다. 그럼 이 어긋난 this를 사용하는 상위 스택으로 가서 문제를 더 알아봐야겠다.

3. Timer

void Timer::DoTimerJob()
{
	/// thread tick update
	LTickCount = GetTickCount64();
 
	while (!mTimerJobQueue.empty())
	{
		const TimerJobElement& timerJobElem = 
			mTimerJobQueue.top();
 
		if (LTickCount < timerJobElem.mExecutionTick)
			break;
 
		timerJobElem.mOwner->EnterLock();
		timerJobElem.mTask();
		timerJobElem.mOwner->LeaveLock();
 
		mTimerJobQueue.pop();
	}
 
 
}
 

문제를 일으키는 Lock은 SyncExecuterable이 소유한 Lock이었고, 문제를 일으킨 호출은 타이머에서 DoTimerJob을 수행할 때 발견되었다. 타이머는 Job들을 timerJobQueue에 저장하고, 틱마다 수행체크를 한다. 이 작업을 하는 것이 DoTimerJob이다. 이때, TimerJobElem에는 SyncExecuterable과 바인딩된 호출 함수, 실행시간 Tick을 가지고 있다. 그런데 이 타이머 조차 TLS에 스레드별로 따로 저장되므로 타이머 자체 저장소가 안정적이며, 실행 순서는 보장될 것이다. 그렇다면 범인은 이 안에 있다.

좀더 천천히 안을 뒤져보자. SyncExecutable은 내부적으로 Lock의 주소를 변경시키지 않는다. 그리고 TimerJobElement도 자신의 멤버 SyncExcutable을 변경시키지 않는다. 따라서 Lock의 주소변경은 오직 TimerJobElement자체의 주소가 변경되었기 때문에 발생한다. 해당 TimerJobElement는 Timer의 TimerJobQueue Top의 상수 참조자이다. 상수이므로 논리적으로 받은 쪽에서 내부 값을 변경시킬 순 없을 것이고, 중간에 Queue의 인터페이스를 통해서 접근하여 변경하였거나, Queue내부적인 문제로 변경되었을 가능성이 있다. 

실제로 dump파일에서 버그난 시점의 timerJobElem 변수와 TimerJobQueue의 탑노드가 서로 다른것을 확인할 수 있었다. 이러한 1번의 문제, 마지막 push한 lock의 주소와 현재 pop할 lock의 주소가 불일치하여 ASSERT에 걸린 것을 감안하면 EnterLock시점에서의 timerJobElem 변수와 LeaveLock시점의 변수가 일치하지 않은 것에서 발생했을 것이다. 따라서 문제는 TimerJobElem의 Task를 진행하는 중에 발생하였다.

4. TimerJobElem의 Task

timerJobElem의 Task는 함수 포인터로 DoSyncAfter란 래퍼함수를 통해서 유저로부터 전달받는다. DoSyncAfter를 사용하는 유저는 SyncExecutable을 상속받은 Player이며, Player는 최초 Start에서 한번, 그리고 초마다 실행되는 OnTick에서 한번 DoSyncAfter를 호출한다.Player의 Start와 OnTick이 위의 락 사이에 호출되는 함수이다. Start는 Player의 초기화 작업을 한뒤 결국 OnTick을 호출하므로 OnTick에서 문제가 발생할 가능성이 높다. 

void Player::OnTick()
{
	//...
        DoSyncAfter(mHeartBeat, GetSharedFromThis<Player>(), 
                    &Player::OnTick);
}

onTick은 주기적으로 호출되기 위해서 자기자신을 DoSyncAfter를 통해서 타이머 큐에 등록한다. 결국 락이 걸리는 중간에 JobQueue에 TimerJobElem이 Push되는 것이다. Queue의 자료 구조가 무엇인지는 아직 보지 못했지만, Push로 인해 전체 주소가 변경될 수 있는 자료구조들은 많이 있다. TimerJobQueue가 이제 유력한 용의자다.

5. TimerJobQueue

typedef std::priority_queue<TimerJobElement, std::deque<TimerJobElement, STLAllocator<TimerJobElement> >, TimerJobComparator> 
TimerJobPriorityQueue;

일단 이 큐는 Priority_queue이다. 그리고 내부 구현체는 메모리 풀의 커스텀 할당자를 사용하는 std::vector로 설정되어있다. Priority_Queue의 Sorting으로 인해 발생하는 위치조정이 의심스럽다. vector로 구현되었기 때문에 Priority-Queue의 sorting이 내부 노드들의 주소에도 영향을 미칠 것이다. 만약 더 우선순위가 높은 elem이 push되면 기존 top 노드의 주소는 새로운 elem크기만큼 뒤로 밀릴 것이고, 기존 주소에 새로운 elem이 들어가게 될 것이다. 

using PriorityQ = std::priority_queue <int, std::vector<int>> ;
int _tmain(int argc, _TCHAR* argv[])
{
	PriorityQ q;
	q.push(2);
	const int& value = q.top();
 
	printf("first address %p, value %d\n", &value, value);
	q.push(3);
	printf("second address %p, value %d\n", &value, value);
 
	return 0;
}

비슷한 환경에서 테스트 해보았고, 위 테스트 결과 value의 값이 push이전과 이후가 서로 달랐다. 주소가 밀려서 데이터 깨짐현상이 발생한 것같다. vector대신 연속공간이 필요없는 deque로 진행해보니 값은 깨지지 않았고, 각각 2, 3이 나왔다. 어느쪽이 되었던 간에 변경되는 자료구조의 특정 주소를 참조자로 받아서 사용하는 것은 위험하다는 것을 알 수 있다. 중간에 push를 뺼수는 없으니, 참조대신 값에 의한 전달을 사용하자. 구조체의 데이터 멤버들은 각각 shared_ptr,stdl::function, int64이기 때문에 default 복사 연산에 문제는 없다. 10번 테스트 한 결과 이상이 없었다.

void Timer::DoTimerJob()
{
	/// thread tick update
	LTickCount = GetTickCount64();
 
	while (!mTimerJobQueue.empty())
	{
		TimerJobElement timerJobElem = mTimerJobQueue.top(); 
 
		//실행할게 하나도 없으면 패스
		if (LTickCount < timerJobElem.mExecutionTick)
			break;
 
		timerJobElem.mOwner->EnterLock();
		
		timerJobElem.mTask();
 
		timerJobElem.mOwner->LeaveLock();
 
		mTimerJobQueue.pop();
	}
}

5. 하지만 나의 추리는 틀렸다.

범인을 잡았다고 히히낙락하고 있는차에 현자 남현욱씨가 와서 이기아리를 외친다.(후...) 그의 의견에 따르면 위 구조자체가 위험한 것은 사실이나 이 사건의 정확한 범인은 아니다. 이유는 OnTick함수와 Priority_queue의 comparator에 있다. OnTick함수는 계속해서 뒤의 시간에 실행될 Elem만 Push한다. 그리고 Priority_queue의 comparator는 실행 시간을 기준으로 우선순위를 매긴다. 따라서 이 코드에서 Priority가 역전되어서 들어가는 경우는 없다. 타이머 자체도 쓰레드 의존적이기 때문에 다른 쓰레드가 다른 시간대의 Job을 Push할일도 만무하다. 그러면 무슨 이유일 것인가? 

어쨌건 JobQueue의 Push동작에서 주소 불일치가 발생하는 것만큼은 확실하다. Vector의 Push가 저지를 수 있는 주소 변경은 realloc이 있다. Vector는 Push할 때 저장 용량이 모자르면 자체적으로 더 큰 용량을 할당받아서 복사작업을 수행한다. 일반적으로는 그 주소 그대로를 사용하지만, 우리는 STLAllocator를 사용한 별도의 메모리 풀에 할당을 받는다. 이 메모리 풀에서 의심스러운 냄새가 난다.

6. 메모리 풀

MemoryPool::MemoryPool()
{
	memset(mSmallSizeMemoryPoolTable, 
               0, sizeof(mSmallSizeMemoryPoolTable));
 
	int recent = 0;
 
	for (int i = 32; i < 1024; i+=32)
	{
		SmallSizeMemoryPool* pool = 
                    new SmallSizeMemoryPool(i);
		for (int j = recent+1; j <= i; ++j)
		{
			mSmallSizeMemoryPoolTable[j] = pool;
		}
		recent = i;
	}
 
	for (int i = 1024; i < 2048; i += 128)
	{
		SmallSizeMemoryPool* pool = 
                    new SmallSizeMemoryPool(i);
		for (int j = recent + 1; j <= i; ++j)
		{
			mSmallSizeMemoryPoolTable[j] = pool;
		}
		recent = i;
	}
 
	for (int i = 2048; i <= 4096; i += 256)
	{
		SmallSizeMemoryPool* pool = 
                    new SmallSizeMemoryPool(i);
		for (int j = recent + 1; j <= i; ++j)
		{
			mSmallSizeMemoryPoolTable[j] = pool;
		}
		recent = i;
	}
 
}

사용중인 메모리 풀에 대해서 조금만 언급하고 넘어가자. 이 메모리 풀은 LFH처럼 작은 사이즈의 Bucket으로 구성된다. 각 Bucket은 테이블을 사용해서 쉽게 접근 가능하다. 가용한 버킷 사이즈가 없으면 그냥 바로 일반 alloc을 통해 할당한다. vector의 custom allocator는 이 메모리풀의 allocate함수를 호출한다. 

void* MemoryPool::Allocate(int size)
{
	MemAllocInfo* header = nullptr;
	int realAllocSize = size + sizeof(MemAllocInfo);
 
	if (realAllocSize > MAX_ALLOC_SIZE)
	{
		header = reinterpret_cast<MemAllocInfo*>(
                _aligned_malloc(
                    realAllocSize, MEMORY_ALLOCATION_ALIGNMENT));
	}
	else
	{
		header = 
                mSmallSizeMemoryPoolTable[realAllocSize]->Pop();
	}
 
	return AttachMemAllocInfo(header, realAllocSize);
}

allocator함수는 요청된 사이즈에 맞는 bucket을 table에서 검색하여 반환해준다. 따라서 MAX_ALLOC_SIZE보다 작은 크기의 vector에 대한 할당요청을 하는 경우, 메모리 풀은 이전에 사용하던 주소와는 다른 주소를 반환해 준다. 따라서 Push할때 기존 Vector의 가용영역이 모자르다면, STLAllocator가 메모리 풀의 새로운 영역을 가져와 반환해주면서, 기존 주소가 달라져버리는 현상이 나타나게 되는 것이다.

7. 그렇다면 댕글링 되서 그전에 에러나야하는 거 아닌가요?

사실은 그렇다 realloc때문에 기존 참조 주소가 없어져서, 사실상 timerJobElem은 댕글링 참조 상태가 되어야한다. 하지만 메모리 풀은 전역이라는 것을 생각해보자. 얘가 할당받은다음에 바로 다른 쓰레드의 JobQueue가 와서 기존에 쓰던 자리를 차지했다면? 사용하는 메모리 양도 비슷할테니, 충분히 가능한 이야기다. 실제로 그것이 일어났습니다. timerJobElem에 남아있는 값이 다른 쓰레드의 JobQueue에서 발견되었다. 

버그가 발견된 17740번 쓰레드의 timerJobElem의 주인은 따로 있다. 현재 큐가 사이즈가 4니까 기존 탑의 위치는 3번째 인덱스일 것이다. 그리고 이런 공교로운 결과가 발견되기 위해서는, 그 딴 주인 쓰레드는 현재 STLAllocator를 통해서 메모리 할당을 막 받았거나 다 받은 상태일 것이다. 그리고 찾았다 요놈!

범인은 16340 쓰레드다. 마침 딱 Push하고 있다가 현행범으로 잡혀왔다. 세번째 인덱스에 있는 Owner의 주소를 보자. 위 쓰레드의 timerJobElem 변수의 값과 동일하지 않은가? 수수께끼는 모두 풀렸다. 문제는 vector의 realloc이고 이것 때문에 EnterLock과 LeaveLock의 주체가 바뀌어 CRASH_ASSERT를 발동시킨 것이다.