qprofile.cpp

编译与调试技巧源代码:qprofile_src

/*
This file is distributed "as is", e.g. there are no warranties 
and obligations and you could use it in your applications on your
own risk. Although your comments and questions are welcome.

Source:			QProfile.cpp
Author:			(c) Dan Kozub, 1999
URL   :			http://members.tripod.com/~DanKozub
Email :			[e-mail], [e-mail]
Last Modified:	Feb 7,1999
Version:		1.3
*/

#include "stdafx.h"
#include "QProfile.h"
#define QPROFILE_MIN_MAX
//comment above line to exclude min-max info collection
//this can speed up profiling a bit 

// Initializing static variables
QProfile *			QProfile::ChainHead=NULL;
int					QProfile::MaxFileNameLen;
LONGLONG      		QProfile::ProgramTime;
LONGLONG      		QProfile::Frequency;
char				QProfile::StrBuffer[QPROFILE_NAMELEN];
bool				QProfile::StopProfiling =false;

LPCSTR				QProfile::OutFile="QProfile.txt";
int					QProfile::OutFileMaxSize = 20000; 
						// after 20K output file will be truncated
int					QProfile::OutputFilter = QProfile_OutputFilters_Time; 
						// by default time in ms is excluded from report
QProfile_Sorting	QProfile::SortBy = QProfile_Sort_PureTime;
int					QProfile::Output=
						QProfile_Out_All|QProfile_Out_File_Append|
						QProfile_Out_Add_Source;
						// write output to all destinations

// This is the main object to measure total time
QProfile			QProfile_Program("Total time");



REM("============QProfile======================")
REM("============QProfile======================")
REM("============QProfile======================")



REM("============QProfile======================")
	QProfile::QProfile(LPCSTR name,bool delete_after_report,
					 LPCSTR file_name, int line_num){
			if (name) ::lstrcpyn(Name,name,QPROFILE_NAMELEN);
			else Name[0]=0;
			DeleteAfterReport = delete_after_report;
			Elapsed = 0;
			LastStart = 0;
			TimeInChildren = 0;
			Counter = 0;
			Running = 0;
			Next = ChainHead; 
			ChainHead = this;
			AutoStarterActive = 0;
			if (!QProfile_Program.IsRunning()) 	QProfile_Program.Start();
			FirstParentFunction = NULL;
			ReportPrinted = false;
			#ifdef QPROFILE_MIN_MAX
				MaxTime=0;
				MinTime=0x7FFFFFFFFFFFFFFF;
			#endif
			FileName=file_name;
			if (lstrlen(file_name) > MaxFileNameLen)  MaxFileNameLen = lstrlen(file_name);
			LineNumber=line_num;
			};


REM("============Reset=========================")
void		QProfile::Reset(){
Elapsed = 0;
LastStart = 0;
Counter = 0;
Running = 0;
#ifdef QPROFILE_MIN_MAX
	MaxTime=0;
	MinTime=0x7FFFFFFFFFFFFFFF;
#endif
};

REM("============PrintSummary==================")
void	QProfile::PrintSummary(){
static bool SummaryAlreadyPrinted = false;
if (SummaryAlreadyPrinted) return; 
	else SummaryAlreadyPrinted = true;
//Summary should be printed only once
StopProfiling=true;
QProfile_Program.Stop(); 
GET_TIMER_FREQ(Frequency);
ProgramTime = QProfile_Program.Elapsed;
char buff[255];
Out("\n----------------- Profiling  results -----------------\n");
SYSTEMTIME time;GetLocalTime(&time);
sprintf(buff,"Date: %02d.%02d.%02d, Time: %02d:%02d.%02d\n",
		time.wDay,time.wMonth,time.wYear,time.wHour,time.wMinute,time.wSecond);
Out(buff);
while(1)
{
	QProfile * max = ChainHead;
	QProfile * cur = ChainHead;
	while(cur){
		if ((*max>*cur)==false) 
								max=cur;
		cur=cur->Next;}
	if (max->ReportPrinted) break;
	max->PrintReport();
} 
Out("\n------------------------------------------------------\n",true,"");
//let's go through all objects once more to delete some
QProfile * cur = ChainHead;
while(cur){
		QProfile * next = cur->Next;
		if (cur->DeleteAfterReport) delete cur;
		cur = next;	}
return;};

REM("============PrintReport===================")
void	QProfile::PrintReport(int level){
ASSERT(TimeInChildren>=0);
if (ReportPrinted) return; ReportPrinted = true;
char buff[255];
char buff2[255];
double elapsed =(double)Elapsed/Frequency*1000;
double share = (double)Elapsed/ProgramTime*100;
double no_children =(double)(Elapsed-TimeInChildren)/Frequency*1000;
double no_children_share = (double)(Elapsed-TimeInChildren)/ProgramTime*100;
static bool first_line = true;
if (first_line){
		Out("------------------------------------------------------\n",false,"");
		Out("|-Child|Total ",false,"");
	if ((OutputFilter&QProfile_OutputFilters_Time)==0)	
		Out("|Time (ms) ");
	if ((OutputFilter&QProfile_OutputFilters_Count)==0)	
		Out("|  Hits  ");
	if ((OutputFilter&QProfile_OutputFilters_TimePerCall)==0)	
		Out("|Time/call ");
#ifdef QPROFILE_MIN_MAX
		Out("|   MIN   |   MAX   ");
#endif
		Out("| Function    \n");
		Out("------------------------------------------------------\n",false,"");}
if (no_children_share == share){
	if (SortBy == QProfile_Sort_Time)
		sprintf(buff,"|      |%6.2lf",no_children_share);
	else
		sprintf(buff,"|%6.2lf|      ",no_children_share);
}else
	sprintf(buff,"|%6.2lf|%6.2lf",no_children_share,share);

if (FileName)
	sprintf(buff2,"%-*.*s(%3d) :",MaxFileNameLen,MaxFileNameLen,FileName,(WORD)LineNumber);
else 
	sprintf(buff2,"");
Out(buff,false,buff2);
if ((OutputFilter&QProfile_OutputFilters_Time)==0){
	sprintf(buff,"|%10.2lf",elapsed);
	Out(buff);}
if ((OutputFilter&QProfile_OutputFilters_Count)==0){
	sprintf(buff,"|%8I64d",Counter);
	Out(buff);}
if ((OutputFilter&QProfile_OutputFilters_TimePerCall)==0){
	sprintf(buff,"|%10.3lf",elapsed/Counter);
	Out(buff);}
Out("|");
#ifdef QPROFILE_MIN_MAX
	if (MinTime==0x7FFFFFFFFFFFFFFF) MinTime = 0;
	sprintf(buff,"%9.3lf|%9.3lf|",
		(double)MinTime/Frequency*1000,
		(double)MaxTime/Frequency*1000);
	Out(buff);
#endif
for(int l=0;l<level;l++) Out("  ");
Out(Name);
if ((DWORD)FirstParentFunction>1){
	sprintf(buff,"(%3.1lf%%)",(double)Elapsed/FirstParentFunction->Elapsed*100);
	Out(buff);}

Out("\n");
if (Output&QProfile_Out_DrawBar){
	double bar_share = no_children_share;
	if (SortBy == QProfile_Sort_Time) bar_share = share;
	Out(PrintBar(bar_share,100,80),false,"");
	Out("\n");}
first_line = false;
if (SortBy == QProfile_Sort_Time){
	QProfile * child = FindNextChild(NULL);
	while(child){
		child->PrintReport(level +1);
		child = FindNextChild(child);}
}
return;};

REM("============PrintBar======================")
char *		QProfile::PrintBar(double val,double max,int length){
static char buff[256];
if (length > 255) length =255;
double to_print = (double)length*val/max;
int to_print_int = (int)to_print;
for(int i=0;i<length;i++){
	while(true){
	if (i==to_print_int){ buff[i]='#'; break;}
	if (i==to_print_int*10){ buff[i]='#';break;}
	if (i<to_print_int){ buff[i]='>'; break;}
	if (i<to_print_int*10){ buff[i]='=';break;}
	buff[i]='.';
	break;}
}
buff[i]=0;
return buff;};

REM("============Out===========================")
bool		QProfile::Out(LPCSTR string,bool last,LPCSTR debug_only){
#ifdef _RPT0
if (Output&QProfile_Out_DebugWindow){
				if (debug_only && (Output&QProfile_Out_Add_Source)){
						if (*debug_only==0) {
								for(int space=0;space<MaxFileNameLen+7;space++)
											_RPT0(_CRT_WARN," ");}
						else 
								_RPT0(_CRT_WARN,debug_only);
						}
				_RPT0(_CRT_WARN,string);
				if (last) _RPT0(_CRT_WARN,"\n");}
#endif
if (Output&QProfile_Out_Consol){
				printf(string);
				if (last) printf("\n");}

if (Output&QProfile_Out_File==0){ return true;}
static HANDLE Handle = NULL;
if (Handle==NULL){
	Handle =::CreateFile(OutFile,GENERIC_WRITE,0,0L,OPEN_ALWAYS,0,0);
	int sz= ::GetFileSize(Handle,NULL);
	if ((Output&QProfile_Out_File_Append) && sz < OutFileMaxSize) ::SetFilePointer(Handle,0,NULL,FILE_END);
	else ::SetEndOfFile(Handle); 
	};
DWORD written = 0;
BOOL ok=::WriteFile(Handle,string,lstrlen(string),&written,NULL);
if (last) ::CloseHandle(Handle);
return true;};

REM("============FindNextChild=================")
QProfile *		QProfile::FindNextChild(QProfile * find_after){
QProfile * cur = ChainHead;
if (find_after) cur =  find_after->Next;
while(cur){
	if (cur->FirstParentFunction == this) return cur;
	cur=cur->Next;}
return NULL;};


REM("============operator>=====================")
bool		QProfile::operator>(QProfile& to_compare){
if (to_compare.ReportPrinted) return true;
if (ReportPrinted) return false;
if (SortBy == QProfile_Sort_Time){
	if (to_compare.FirstParentFunction!=FirstParentFunction)
							return (DWORD)FirstParentFunction<=1;}
switch(SortBy){
	case QProfile_Sort_Time:
		if (Elapsed > to_compare.Elapsed) return true;
		else return false;
	case QProfile_Sort_PureTime:
		if (Elapsed-TimeInChildren > 
			to_compare.Elapsed - to_compare.TimeInChildren) return true;
		else return false;
	case QProfile_Sort_Count:
		if (Counter > to_compare.Counter) return true;
		else return false;
	case QProfile_Sort_TimePerCall:
		if ((double)Elapsed/Counter > 
				(double)to_compare.Elapsed/to_compare.Counter ) return true;
		else return false;
	default: return false;}
return false;};





REM("============QProfileStarter===============")
REM("============QProfileStarter===============")
REM("============QProfileStarter===============")

_declspec(thread) QProfileStarter * QProfileStarter::LastActive=NULL;
REM("============RecursiveCallFrom=============")
QProfileStarter *	QProfileStarter::RecursiveCallFrom(){
QProfileStarter * cur = Parent;
while(cur){
		if (cur->Profile==Profile) return cur;
		cur=cur->Parent;}
return NULL;}

REM("============QProfileStarter===============")
QProfileStarter::~QProfileStarter(){
		if (QProfile::StopProfiling) return;
		LONGLONG       now;
		GET_TIMER_VALUE(now);
		LONGLONG       elapsed = now-StartTime;
		LastActive = Parent;
		bool maybe_recursive = (--Profile->AutoStarterActive) > 0;
		#ifdef QPROFILE_MIN_MAX
			if (elapsed>Profile->MaxTime) 
						Profile->MaxTime=elapsed;
			if (elapsed<Profile->MinTime) 
						Profile->MinTime=elapsed;
		#endif
		if (!Parent){
				Profile->Add(elapsed,TimeInChildren); return;}
		// checking calling function to be unique caller
		if (!Profile->FirstParentFunction){
			Profile->FirstParentFunction = Parent->Profile;}
		else{
			if (Profile->FirstParentFunction!=Parent->Profile) 
					Profile->FirstParentFunction = (QProfile*)(DWORD)1;}
			

		QProfileStarter * recursive = NULL;
		if (maybe_recursive)	
					recursive=RecursiveCallFrom();
		
		if (!recursive){ 
			Profile->Add(elapsed,TimeInChildren);
			Parent->TimeInChildren+=elapsed;}
		else {
			Profile->Counter++;
			if (recursive==Parent){
				Parent->TimeInChildren+=TimeInChildren;}
			else {
				Parent->TimeInChildren+=elapsed;
				//time in recursive call should be excluded
				recursive->TimeInChildren -= elapsed-TimeInChildren;}}
return;}