3. [C++] Rate my profiler

[C++] Rate my profiler

  • A

    So, da ist er nun - mein Profiler. Was ein Profiler ist und wozu er dient:
    Ein Profiler ist eine Klasse/Tool, mit dem man ausgewählte Funktionen auf Effizienz testen kann - das Ergebniss landet in meinem Fall in einer log.html. Diese umfasst folgende Informationen: Gesamte verbrauchte Zeit, Durchläufe insgesamt, Durschnittszeit, Min und Max. So kann man gezielt die Funktionen raussuchen, die Springen (hohe max- und niedrige min-Werte relativ zur Durschnittszeit) oder allgemein zuviel Zeit verbrauchen.
    Der BspCode:
    [Main]

    #include "main.h"

void FuncA()
{   CProfile FuncA(funcA);
   Sleep(444);
};

void FuncB()
{   CProfile FuncB(funcB);
   Sleep(222);
};

void main()
{   ProfileMgr()->Register();
   while(!kbhit())
   {   FuncA();
      FuncB();
   }
   ProfileMgr()->LogProfiles();
};

    #ifndef main_h
#define main_h

#include <windows.h>
#include <conio.h>
#include "profiler.h"

using namespace std;

#endif // main_h

    [Profiler]

    #ifndef profiler_h
#define profiler_h

#ifndef _MSC_VER
#define __forceinline inline
#endif

#include <windows.h>
#include <cassert>
#include <string>
#include <fstream>
#include <ctime>
#include <clocale>

using namespace std;

const unsigned int uiSize(2);

const char ProfileDescriptions[uiSize][64] = {   "funcA",
                                    "funcB",
                                          };

enum profiles
{   funcA,
   funcB
};

struct profiledata
{   string         m_strName;
   unsigned long   m_ulId;
   unsigned long   m_ulTime1, m_ulTime2;
   unsigned long   m_ulCnt;
   unsigned int   m_uiMin, m_uiMax;

   void         Init()
   {   m_ulId = m_ulTime1 = m_ulTime2 = m_ulCnt = m_uiMax = 0;
      m_uiMin = 12345;
   };
};

class CProfileMgr
{      unsigned long   m_ulID;
      bool         m_bRegistered;
      float         fTperMS;
      char         m_szTimeStamp[32];

                  CProfileMgr() : m_ulID(0), m_bRegistered(false), fTperMS(0.0f)
                  {   DWORD dwLow, dwHigh;
                     __asm {
                        rdtsc
                        mov dwLow, eax
                        mov dwHigh, edx
                     }
                     LONGLONG b, a = ((unsigned __int64) dwHigh << 32) | (unsigned __int64) dwLow;
                     Sleep(500);
                     __asm {
                        rdtsc
                        mov dwLow, eax
                        mov dwHigh, edx
                     }
                     b = ((unsigned __int64) dwHigh << 32) | (unsigned __int64) dwLow;
                     fTperMS = float((b - a) / 500);
                  };
      void         GetTimestamp();

   public:
      unsigned long   PTime();
      profiledata      m_Data[uiSize];
      void         Register();
      void         LogProfiles();
                  ~CProfileMgr()   { };
      __forceinline static CProfileMgr* cGetInstance()
      {   static CProfileMgr pInstance;
         return &pInstance;
      };

      unsigned long   Register(char *pName);
}; // class CProfileMgr

__forceinline static CProfileMgr* ProfileMgr()
{   return CProfileMgr::cGetInstance();
};

class CProfile
{   profiledata   *p;
   public:      CProfile(unsigned long ulID);
            ~CProfile();
}; // class CProfiler

#endif // profiler_h

    #include "profiler.h"

CProfile::CProfile(unsigned long ulID) : p(NULL)
{   p = &ProfileMgr()->m_Data[ulID];
   p->m_ulTime1 = ProfileMgr()->PTime();
   p->m_ulCnt++;
};

CProfile::~CProfile()
{   long t = (ProfileMgr()->PTime() - p->m_ulTime1);
   p->m_ulTime2 += t;
   if(p->m_uiMax < t)
      p->m_uiMax = t;
   else if(p->m_uiMin > t)
      p->m_uiMin = t;
};

// green      : #017f05
// red         : #d60000
// orange      : #e59c0b
// light blue   : #6699cc

void CProfileMgr::LogProfiles()
{   ofstream prflog("prflog.html", ios::out);
   GetTimestamp();
   prflog << "<hmtl><head><title>ProfileLog.hmtl</title></head><body bgcolor=\"#464646\"><font color=\"green\">";
   prflog << "\tTIME & DATE: " << m_szTimeStamp << " </font><br><br>";

   for(unsigned int i = 0; i < uiSize; ++i)
   {   prflog << "<font color=\"#017f05\">" << "<table border=\"2\" bordercolor=\"#1c1b68\">";
      prflog << "<colgroup><col width=\"120\"><col width=\"320\"></colgroup><tr>";
      prflog << "<th>NAME</th><th>" << m_Data[i].m_strName << "</th></tr><tr>";
      prflog << "<th>ID</th><th>" << m_Data[i].m_ulId << "</th></tr><tr>";
      prflog << "<th>TIME</th><th>" << m_Data[i].m_ulTime2 << "</th></tr><tr>";
      prflog << "<th>CNT</th><th>" << m_Data[i].m_ulCnt << "</th></tr><tr>";
      prflog << "<th>TIMEAVE</th><th>" << float(m_Data[i].m_ulTime2)/m_Data[i].m_ulCnt << "</th></tr><tr>";
      prflog << "<th>TIMEMAX</th><th>" << m_Data[i].m_uiMax << "</th></tr><tr>";
      prflog << "<th>TIMEMIN</th><th>" << m_Data[i].m_uiMin << "</th></tr><tr>";
      prflog << "</table><br></font>";
   }

   prflog.close();   
};

void CProfileMgr::GetTimestamp()
{   time_t Time;
   time(&Time);
   strftime(m_szTimeStamp, 32, "%H:%M:%S %d.%m.%y", localtime(&Time));
};

void CProfileMgr::Register()
{   for(unsigned int i = 0; i < uiSize; ++i)
   {   m_Data[i].Init();
      m_Data[i].m_strName = ProfileDescriptions[i];
      m_Data[i].m_ulId = i;
   }
   m_bRegistered = true;
   return;
};

unsigned long CProfileMgr::PTime()
{   DWORD dwLow, dwHigh;
   __asm {
      rdtsc
      mov dwLow, eax
      mov dwHigh, edx
   }
   return unsigned long(LONGLONG(((unsigned __int64) dwHigh << 32) | (unsigned __int64) dwLow)/fTperMS);
};

    An code ist das eigentlich relativ wenig - ich hoffe mal so viel Leute wie möglich schaun sich das Teil an 🙂

    Ich habe hierbei das Hinzufügen von Funktionen so gestaltet, dass sie schon vorher in die profiler.h eingetragen werden müssen (mit Namen und identifier) - das erspart die Zeitraubende strcmp-func.

    Sollten noch Funktionen fehlen, so bin ich ganz Ohr 🙂

    Kurze Beschreibung, wie er funktioniert:
    Der Profiler funktioniert folgender maßen:
    Es gibt ein SingletonProfileManager (CProfileMgr), der die ganzen Profiles verwaltet. Mit ProfileMgr()->Register(); werden die Profiles dann in die Verwaltung mit aufgenommen.
    Von da an können die gespeicherten Profiles per CProfile something(enum_profile); gestartet werden. Das erstellte Objekt trägt sich per Konstruktor im Manager ein und wenn der Namensbereich verlassen wird, zerstört sich das Objekt automatisch und trägt sich imer Manager wieder aus. Dabei werden jedes mal die Zeiten genommen (der asmKram). Am Ende wird die Sache einfach per ProfileMgr()->LogProfiles(); in eine html gekloppt (natürlich schön in tabellenform).

    Sollte nochwas unklar sein - sagts einfach.

    0
  • S

    Das mit dem enum gefällt mir persönlich weniger.

    Ein overall profiling macht mir ein 'echter' profiler.
    Solche profiler-klassen wie deine würde ich zum speziellen auffinden des performance problemes suchen.

    mein vorschlag:
    mach zusätzlich zum enum noch eins möglichkeit mit char* zu arbeiten.
    So dass man die enums verwenden kann, aber wenn man will auch mal nen char*

    0
  • A

    Danke für den Tip ShadeOfMine.

    Vielleicht findet sich noch einer, der was an dem Code zu bemengeln hat? Bitte! 🙂

    0
  • P

    am code ist auf jeden fall zu bemaengeln, dass du nach einer offnenden klammer auf der selben zeile weiterschreibst.
    und wie soll das mit den enums ueberhaupt gehen?
    da musst du ja als autor der bibliothek schon alle namen der bloecke kennen, die jemals einer profilen will!
    und muesste man vielleicht noch den overhead von sleep berechnen?
    also (timeFor(Sleep(500)) - timeFor(Sleep(0)))/500 ?
    oder macht Sleep das selbst?

    0
  • A

    ..., dass du nach einer offnenden klammer auf der selben zeile weiterschreibst.

    Wieso? Bitte begründen.

    da musst du ja als autor der bibliothek schon alle namen der bloecke kennen, die jemals einer profilen will!

    Das ist korrekt - dies geschah im Sinne der Performance um das Ergebniss möglichst unverfälscht zuhalten. Um aber auch einfach mal so Funktionen zu überwachen hatte ShadeOfMine bereits vorgeschlagen auch die char* Version noch als Möglichkeit zu implementieren.

    und muesste man vielleicht noch den overhead von sleep berechnen?
    also (timeFor(Sleep(500)) - timeFor(Sleep(0)))/500 ?
    oder macht Sleep das selbst?

    Ja, macht es - aber auf kurze Zeiten ist Sleep ungenau, deswegen die 500. Über eine Ungenauigkeit von 1 auf 500 ms kann ich hinwegsehen.

    Danke, dass du dir dafür Zeit genommen hast.

    [ Dieser Beitrag wurde am 18.03.2003 um 11:05 Uhr von awesome editiert. ]

    0
  • ?

    SetThreadPriority(REALTIME_PRIORITY_CLASS) fehlt mir in deinem Code noch

    0
Anmelden zum Antworten