#include "sysinc.h" #include #include #ifdef MGL_PROFILING /**********************************************************************************************************************/ void dbg_CreateProfilingFromNames(MGLProfile* profile, uint32 numItems, const char** itemNames) { struct EClockVal dummy; float64 clockFreq; profile->clockScale = 0; profile->profileNames = 0; profile->profileCnt = 0; profile->profileData = 0; if (!IExec || !ITimer || numItems<1 || !itemNames) { return; // this is totally bogus! } clockFreq = (float64)ITimer->ReadEClock(&dummy); profile->clockScale = 1000000.0 / clockFreq; MGLProfileItem* profileItems = (MGLProfileItem*) IExec->AllocVecTags( sizeof(MGLProfileItem)*numItems, AVT_Type, MEMF_SHARED, AVT_Lock, FALSE, AVT_ClearWithValue, 0, TAG_END ); if (profileItems) { uint32 i; for (i=0; i< numItems; i++) { profileItems[i].minEClocks = 0x7FFFFFFF; //IExec->DebugPrintF("MGL:Added %s to Profiler\n", itemNames[i]); } profile->profileNames = itemNames; profile->profileCnt = numItems; profile->profileData = profileItems; IExec->DebugPrintF("MGL:Created Profiling\n"); } else { IExec->DebugPrintF("MGL:Error creating profiling\n"); } } /**********************************************************************************************************************/ void dbg_DestroyProfiling(MGLProfile* profile) { profile->profileNames = 0; profile->profileCnt = 0; if (profile->profileData) { IExec->FreeVec(profile->profileData); profile->profileData = 0; IExec->DebugPrintF("MGL:Destroyed Profiling\n"); } } /**********************************************************************************************************************/ void dbg_EndProfiling(MGLProfileItem* p) { /* We only update successful calls, so call this at the end of a function before a valid return */ union { struct EClockVal ecv; uint64 u64; } current, mark; uint32 ticks; mark.ecv = p->mark; //ITimer->ReadEClock(¤t.ecv); dbg_ReadEClock(¤t.ecv); ticks = (uint32)(current.u64 - mark.u64); if (ticks < p->minEClocks) { p->minEClocks = ticks; } if (ticks > p->maxEClocks) { p->maxEClocks = ticks; } p->totEClocks += ticks; ++p->numCalls; } /**********************************************************************************************************************/ void dbg_ClearProfiling(MGLProfile* profile) { if (profile) { int32 i = profile->profileCnt; MGLProfileItem* p = profile->profileData; while (i--) { p->numCalls = 0; p->totEClocks = 0; p->minEClocks = 0x7FFFFFFF; p->maxEClocks = 0; ++p; } } } /**********************************************************************************************************************/ #define DEBUGPRINTF_NOFLOAT void dbg_LogProfiling(MGLProfile* profile) { uint32 i; MGLProfileItem* p = profile->profileData; //float64 overallTime = profile->clockScale * p->totEClocks; IExec->DebugPrintF("MGL:Profiling statistics (only showing profiled items that were actually called):\n"); for (i=0; i < profile->profileCnt; i++) { float64 totalTime = profile->clockScale * p[i].totEClocks; float64 callTime = 0.0; uint32 calls = p[i].numCalls; if (calls) { if (profile->profileNames[i][0]!='*') { #ifdef DEBUGPRINTF_NOFLOAT float64 temp; uint32 callTimeA, callTimeB; uint32 totalTimeA, totalTimeB; uint32 fractionA, fractionB; uint32 minTimeA, minTimeB; uint32 maxTimeA, maxTimeB; #endif callTime = totalTime / (float64)calls; #ifdef DEBUGPRINTF_NOFLOAT //temp = 100.0*totalTime/overallTime; callTimeA = (uint32) callTime; callTimeB = (uint32) (100.0*(callTime - ((float64)callTimeA))); totalTimeA = (uint32) totalTime; totalTimeB = (uint32) (100.0*(totalTime - ((float64)totalTimeA))); // fractionA = (uint32) temp; // fractionB = (uint32) (100.0*(temp - ((float64)fractionA))); temp = profile->clockScale * p[i].minEClocks; minTimeA = (uint32) temp; minTimeB = (uint32) (100.0*(temp - ((float64)minTimeA))); temp = profile->clockScale * p[i].maxEClocks; maxTimeA = (uint32) temp; maxTimeB = (uint32) (100.0*(temp - ((float64)maxTimeA))); IExec->DebugPrintF( "%28s : %8lu calls, %9lu.%02lu us, "/*[%3lu.%02lu%%]*/" %5lu.%02lu us/call [min:%5lu.%02lu max:%7lu.%02lu]\n", profile->profileNames[i], calls, totalTimeA, totalTimeB, //fractionA, fractionB, callTimeA, callTimeB, minTimeA, minTimeB, maxTimeA, maxTimeB ); #else IExec->DebugPrintF( "%28s : %8lu calls, %12.2f us, "/*[%6.2f%%]*/" %8.2f us/call [min:%8.2f max:%10.2f]\n", profile->profileNames[i], calls, totalTime, //100.0*totalTime/overallTime, callTime, profile->clockScale * p[i].minEClocks, profile->clockScale * p[i].maxEClocks ); #endif } else { IExec->DebugPrintF( "%28s : %8lu calls\n", profile->profileNames[i], calls ); } } } IExec->DebugPrintF("\n"); } #endif