본문 바로가기

디버그 기록

채팅서버 메모리 누수 시즌2

저번에 분명히 누수를 전부 다 잡앗다고 생각햇는데 하루정도 지나서 이번에는 저번처럼 급격하게 메모리가 올라가지는 않지만 45퍼센트에서 하루만에 60퍼센트로 1GB넘게 늘어난걸 확인했다.

원인을 찾기 위해서 우선 TLS 풀의 버킷사이즈를 1로 만들엇다.

누수가 난 갯수를 정확하게 확인하기 위함이다.

 

또한 매번 누수가 날때마다 디버깅용 함수를 썻다 지웟다 하기가 싫어서 이번기회에 함수를 매크로로 묶엇다.

#ifdef DEBUG_LEAK
	enum LEAK_EVENT
	{
		ALLOC_CS_CHAT_REQ_MESSAGE,
		SEND_PACKET,
		SEND_ERROR,
		SEND_PENDING_DISCONNECTED,
		SMART_PACKET_DESTRUCTOR,
		RELEASE_SESSION,
		SEND_PROC,
		WRITE_SEND_PACKET_ARR,
	};
	struct LEAK_LOG
	{
		LEAK_EVENT event;
		int refCnt;
		LINKED_NODE logListLink = offsetof(LEAK_LOG,logListLink);
		Packet* pPacket;
		Session* pSession;
		ID sessionID;
		int sendBufIndex;
	};
	char funcName_[100];
	//// Start함수에서 초기화
	static inline CRITICAL_SECTION cs_for_debug_leak;
	CRITICAL_SECTION cs_for_log_list_;
	CLinkedList logList_;
	static inline CTlsObjectPool<LEAK_LOG, false> leakLogPool;
#ifdef DEBUG_LEAK_STD_LIST
	static inline std::list<Packet*> debugList;
#else
	LINKED_NODE pDebugLink;
	static inline CLinkedList debugList{ 200 };
#endif

	template<ServerType type>
	static Packet* AllocForDebugLeak(const char* pFuncName)
	{
		Packet* pPacket = packetPool_.Alloc();
		strcpy_s(pPacket->funcName_, _countof(pPacket->funcName_), pFuncName);
		pPacket->Clear<type>();
		EnterCriticalSection(&cs_for_debug_leak);
		debugList.push_back(pPacket);
		LeaveCriticalSection(&cs_for_debug_leak);
		return pPacket;
	}

	static void FreeForDebugLeak(Packet* pPacket)
	{
		EnterCriticalSection(&cs_for_debug_leak);
		debugList.remove(pPacket);
		LeaveCriticalSection(&cs_for_debug_leak);

		EnterCriticalSection(&pPacket->cs_for_log_list_);
		LEAK_LOG* pLeakLog = (LEAK_LOG*)pPacket->logList_.GetFirst();
		while (pLeakLog != nullptr)
		{
			LEAK_LOG* pTemp = pLeakLog;
			pLeakLog = (LEAK_LOG*)pPacket->logList_.remove(pLeakLog);
			Packet::leakLogPool.Free(pTemp);
		}
		LeaveCriticalSection(&pPacket->cs_for_log_list_);
		packetPool_.Free(pPacket);
	}

	LEAK_LOG* WRITE_PACKET_LOG(LEAK_EVENT event, int refCnt, Session* pSession, ID sessionID, int sendBufIdx = -1)
	{
		LEAK_LOG* pLeakLog = leakLogPool.Alloc();
		pLeakLog->event = event;
		pLeakLog->refCnt = refCnt;
		pLeakLog->pPacket = this;
		pLeakLog->pSession = pSession;
		pLeakLog->sessionID = sessionID;
		pLeakLog->sendBufIndex = sendBufIdx;
		EnterCriticalSection(&cs_for_log_list_);
		logList_.push_back(pLeakLog);
		LeaveCriticalSection(&cs_for_log_list_);
		return pLeakLog;
	}
#endif

DEBUG_LEAK이라는 매크로를 해제하면 전부 없애버릴수 잇게 매크로로 우선 묶는다.

이후 파일 상단에 이런식으로 매크로 함수로 래핑한다.

PACKET_ALLO에서는 미리 정의된 매크로로 함수이름을 받아서 위의 코드에 funcName_이라는 직렬화 버퍼의 멤버변수에 복사한다. 이전에는 AllocType이라는 enum 매개변수가 잇엇고 기본인자를 정해줄수가 없어서 함수 인터페이스가 디버깅용과 일반용이 구분되지 않앗고 매번 모든 코드를 수정해야햇는데 _func_ 매크로를 기본인자로 정해주고 funcName_이라는 직렬화 버퍼의 멤버변수 배열에 복사함으로서  매번 어디서 할당되엇는지를 매개변수로 넣어주지 않아도 된다.

따라서 DEBUG_LEAK만 직렬화 버퍼 헤더상단에 정의하면 누수가 발생한 직렬화 버퍼가 어디서 할당되엇는지를 바로 알수 있게된다.

 

 

 

저번과 같은 방법으로 서버를 종료시키고 누수난 직렬화버퍼를 리스트에서 꺼내서 funcName__ 멤버를 콘솔창에 출력해보니 CS_CHAT_REQ_MESSAGE에서 누수가 나는것을 확인했다.

12시간을 켜두고 누수가 80개가 넘게 낫을때도 전부 CS_CHAT_REQ_MESSAGE임을 확인했다.

 

해당 함수는 클라가 서버에게 메시지를 쏘고싶다고 요청하면 서버가 해당클라를 포함한 섹터의 모든 플레이어에게 메시지를 쏴준다.  하나의 직렬화버퍼를 포인터를 reference count를 이용해서 여러클라에게 보내는 컨텐츠는 이것밖에없으니 당연히 RefCnt에 문제가 있다고 생각하고, 로그를 찍어 추적을 시작했다. 

 

하나의 직렬화 버퍼에서 어떤 과정이 발생하는 지를 추적하기위해서 

직렬화 버퍼마다 로그를 저장해야한다. 문제가 발생하자마자 멈추게 하는것이 불가능하므로 종료후 누수 발생 시점에서 원형 배열이므로  직렬화 버퍼의 로그를 이미 덮어씌워졋을것이기 때문이다.

 

 

직렬화 버퍼의 멤버변수로 로그를 저장할 리스트를 선언한다 

또한 로그구조체를 할당할 TlsPool도 할당한다.

SEND_ERROR 즉 WSASend호출 이후 바로 에러가 발생한 횟수를 0에서 더하면 마지막 refCnt가 나온다.

Session해제함수에서도 로그를 찍도록 햇는데 호출되지 않아서 모든 세션을 연결을 끊도록 유도해도 모두 Release가 되는것도 확인햇다. 혹시 몰라서 로그구조체에 SessionID와 Session*를 추가하고 살펴보게된다. 

IoCnt_ 최상위 비트가 1이고 pSession->sessionId_와 sessionId가 다른걸 봐서 해제도 제대로 되엇다.

따라서 ReleaseSession에는 문제가 없다는것이다.

SendPost에서 WSASend 호출전에 Session 멤버변수인 pSendPacketArr_(완료통지 전에 직렬화버퍼를 저장해둘 배열)

에 저장하는 시점에서 락프리큐에서 디큐하고 이후 WSASend 호출 이후 SendError 로그가 찍히기때문에 락프리큐의 문제는 아니다. 

 

SendPacket에서 SendPost를 호출하는데 SendPost는 Send 1회제한때문에 한번에 하나의 스레드만 진입할수 있다.

SendPost 에서는 SendFlag를 설정하고 완료통지 이전 혹은 Session 재초기화 전까지는 FALSE로 초기화 되지 않는다.

로그를 보다가 SEND_ERROR에서 세션ID가 중복되는걸 보고 여러개의 플레이어가 하나의 플레이어에게 직렬화 버퍼 포인터로 메시지를 쏠때  설마 SendPost에 어떠한 이유로 Release되기이전에 여러번 접근해서  Release 이전에 pSendPacketArr_에  직렬화버퍼 포인터를 덮어씌운다고 추정하게된다.

 

WSASend 아래에서 오류가 발생시 bSendingInProgress_(SendFlag임)를 해제하는것을 발견한다.

즉 오류 발생마다 SendFlag가 해제되니 다른 플레이어가 다시 메시지를 보내려고 진입해서 이전 플레이어의 pSendPacketArr_에서의 직렬화버퍼 포인터를 덮어쓰는것으로 추정된다.

 

이를  증명하기위해 pSendPacketArr_에 직렬화버퍼 포인터를 복사할때마다 해당 인덱스를 로그에 추가한다.

예를 들어 4447143120, 4304865864라는 ID를 가진 세션은 Release된 시점에서 2명씩이 SEND_ERROR를 띄우고 나간다.

같은 0번인덱스에 덮어 씌운것을 알수있다.

 

마찬가지로 덮어 씌운것을 알수잇다.

'디버그 기록' 카테고리의 다른 글

Resoure naming으로 메모리 누수 잡기  (0) 2024.10.25