追踪多线程调用路径关系

 在阅读多线程程序时，最头疼的就是不知道那些程序运行在同一个线程中。下面的程序可以方便的加入到代码中，并且记录下各个线程调用路径：

 .h file:

#ifndef UTILITY_H_HZ_FW
#define UTILITY_H_HZ_FW

#include <Windows.h>
#include <windef.h>
#include <stdio.h>
#include <iostream>
#include <fstream>
#include <string>

#include <map>
#include <list>
#include <vector>

using namespace std;

// my definition
//===============
enum eOPER {REPLACE, DONOTHING, PUSHBACK};

// facility class to use critical section as lock. 
// critical section must be initialized before using this class
class CSLock {
public:
	CSLock(CRITICAL_SECTION &cs) : _cs(cs){
		EnterCriticalSection(&_cs);
	}
	~CSLock() {
		LeaveCriticalSection(&_cs);
	}
private:
	CRITICAL_SECTION &_cs;
};

class GetTimeStamp {
public:
	GetTimeStamp()
	{
		m_dwp = SetThreadAffinityMask(GetCurrentThread(), 0x1);
		if (m_dwp == 0)
		{
			cout << "set thread affinity failed: " << GetLastError() << endl;
		}
	}
	~GetTimeStamp()
	{
		if (m_dwp != 0)
			SetThreadAffinityMask(GetCurrentThread(), m_dwp);
	}
	string TimeStamp()
	{
		LARGE_INTEGER liPerfCount;
		QueryPerformanceCounter(&liPerfCount);

		LARGE_INTEGER liPerfFreq;
		QueryPerformanceFrequency(&liPerfFreq);

		__int64 iMs = liPerfCount.QuadPart * 1000 / liPerfFreq.QuadPart;
		char buf[11] = {0};
		sprintf(buf, "%I64d", iMs);
		return buf;
	}
private:
	DWORD_PTR m_dwp;
};

class FileWriter
{
public:
	FileWriter(const string& strFileName)
		: m_ofs(strFileName)
	{
	}
	~FileWriter()
	{
		m_ofs.close();
	}
	void WriteMessage(const string& strMessage, bool bAddTimestamp = true)
	{
		if (bAddTimestamp)
			m_ofs.write(m_timestamp.TimeStamp().append("-").c_str(), m_timestamp.TimeStamp().length()+1);
		m_ofs.write(strMessage.c_str(), strMessage.length());
		m_ofs.write("\n", 1);
		m_ofs.flush();
	}
	void WriteMessageInLine(const string& strMessage, bool bAddTimestamp = true)
	{
		if (bAddTimestamp)
			m_ofs.write(m_timestamp.TimeStamp().append("-").c_str(), m_timestamp.TimeStamp().length()+1);
		m_ofs.write(strMessage.c_str(), strMessage.length());
		m_ofs.flush();
	}
private:
	ofstream m_ofs;
	GetTimeStamp m_timestamp;
};

// singleton class to record call chain for multiple threads
// data structure: 
//	thread 0: chain_1 (func1 -> func2 -> ... )
//			  chain_2 (func1 -> func2 -> ... )
//			  ...

//	thread 1: chain_1 (func1 -> func2 -> ... )
//			  chain_2 (func2 -> func2 -> ... )
//			  ...
//	...
class CallChainWithThread
{
public:
	// get this singleton class' instance
	static CallChainWithThread* Instance() {
		if (_pInst == 0) {
			_pInst = new CallChainWithThread();
		}

		return _pInst;
	}

	// add a call to a thread's call chain
	void AddACall(DWORD aDWThreadID, string aStrFuncName){
		CSLock csLock(_cs);
		_mapActiveRecords[aDWThreadID].push_back(aStrFuncName);
		if (UpdateRecord(aDWThreadID, _mapActiveRecords[aDWThreadID]) != DONOTHING)
			FlushFinalRecord();
	}

	// remove a cal from a thread's call chain
	void DelCall(DWORD aDWThreadID, string aStrFuncName=""){
		CSLock csLock(_cs);
		_mapActiveRecords[aDWThreadID].pop_back();

		// no need to update the final record, as we are only interested the longer record in the final record 
	}

protected:
	CallChainWithThread() :
		 _fw("houzhe_thread_recrod.txt")
	{
		InitializeCriticalSection(&_cs);
	}

	~CallChainWithThread()
	{
		// FlushFinalRecord();
		DeleteCriticalSection(&_cs);
	}
private:
	// private methods
	//=================

	// update record according to a new call chain of the thread
	eOPER UpdateRecord(DWORD aDWThreadID, const list<string> & aLstRecord)
	{
		if (_mapRecords.find(aDWThreadID) == _mapRecords.end()) {
			// if this is the first call chain of the thread, we just push it back
			_mapRecords[aDWThreadID].push_back(aLstRecord);
			return DONOTHING;
		}

		// if an existing record is only part of the new one, we need replace it; 
		// if an existing record is same or is longer than the new one, we need do nothing
		// otherwise, we just push it back.
		eOPER opera = PUSHBACK;

		vector< list<string> >::iterator iter = _mapRecords[aDWThreadID].begin();
		while (iter != _mapRecords[aDWThreadID].end()) {
			list<string>::const_iterator newRecIter = aLstRecord.begin();
			list<string>::const_iterator oldRecIter = (*iter).begin();
			while ((newRecIter != aLstRecord.end()) && (oldRecIter != (*iter).end()) && (*newRecIter == *oldRecIter)) {
				newRecIter++;
				oldRecIter++;
			}

			if ((newRecIter != aLstRecord.end()) && (oldRecIter == (*iter).end())) {
				// _mapRecords[aDWThreadID].erase(iter);
				// _mapRecords[aDWThreadID].push_back(aLstRecord);
				// return;
				opera = REPLACE;
				break;
			}
			
			if (newRecIter == aLstRecord.end()) {
				opera = DONOTHING;
				break;
			}
			iter++;
		}
		if (opera == REPLACE) {
			_mapRecords[aDWThreadID].erase(iter);
			_mapRecords[aDWThreadID].push_back(aLstRecord);
		}
		else if (opera == PUSHBACK) {
			_mapRecords[aDWThreadID].push_back(aLstRecord);
		}
		return opera;
	}

	// flush the final records to file
	void FlushFinalRecord() {
		map<DWORD, vector< list<string> > >::iterator iter = _mapRecords.begin();
		while (iter != _mapRecords.end()){
			char buf[100] = {0};
			sprintf(buf, "Thread %u:", iter->first);
			_fw.WriteMessage(buf);
			vector< list<string> >::iterator vecIter = iter->second.begin();
			while (vecIter != iter->second.end()) {
				list<string>::iterator lstIter = vecIter->begin();
				while (lstIter != vecIter->end()) {
					_fw.WriteMessageInLine(*lstIter, false);
					_fw.WriteMessageInLine(" -> ", false);
					lstIter++;
				}
				_fw.WriteMessageInLine("\n", false);
				vecIter++;
			}
			iter++;
		}

		_fw.WriteMessageInLine("=============================\n", false);
		_fw.WriteMessageInLine("\n", false);
	}

	// private members
	//================

	static CallChainWithThread *_pInst;					// this singleton class' instance
	map<DWORD, vector< list<string> > > _mapRecords;	// records of all threads' call chain
	map<DWORD, list<string> > _mapActiveRecords;		// active call chain of all threads

	FileWriter _fw;										// file to write records in 
	CRITICAL_SECTION _cs;								// protect _mapRecords and _mapActiveRecords
};

// Facility class to use CallChainWithThread. Initialize this class
// at the beginning of every function to record its call chain with thread information.
class FileInfoWithThread
{
public:
	FileInfoWithThread() {

	}
	FileInfoWithThread(const string& funcName){
		CallChainWithThread::Instance()->AddACall(GetCurrentThreadId(), funcName);
	}

	~FileInfoWithThread(){
		CallChainWithThread::Instance()->DelCall(GetCurrentThreadId());
	}

};

#endif

.cpp file

#include "houzhe_utility_filewriter.h"

CallChainWithThread *CallChainWithThread::_pInst = 0;

使用：

void f()
{
    FileInfoWithThread fiwt(__FUNCTION__);
}

输出举例：

27504647-Thread 8808:
RTCPThreadRun -> SetSocketList -> 
27504647-Thread 9324:
initScpHandler -> initScpHandlerInternal -> setVtbl -> 
registNotificationCallback -> registNotificationCallbackInternal -> findCallbackInList -> 
InitRtcpHandler -> InitSocket -> 
startRTCPDaemonThread -> 

刚刚发现这里实际有两个bug:

1. 因为singleton是new出来的，所以在程序退出时它的析构函数并没有被调用。建议放一个全局变量并在该变量的析构函数中调用CallChainWithThread的FlushFinalRecord（）。

2. 是一个设计问题。因为所有的追踪是基于thread id的，考虑有些程序经常创建和销毁线程，如果thread id被重复生成，追踪的结果就不准确了。