(C++) Simple speed profiler

Post those lines of code you feel like sharing or find what you require for your project here; or simply use them as tutorials.
Post Reply
CuteAlien
Admin
Posts: 9628
Joined: Mon Mar 06, 2006 2:25 pm
Location: Tübingen, Germany
Contact:

(C++) Simple speed profiler

Post by CuteAlien »

Reason for this profiler: Normal profilers like gprof are one way to find bottlenecks, but in games the most important stuff is often the peaktimes of some lines, or we need to find out the times of a specific piece of code.

Features: This profiler uses a few defines which can be added in code and can be removed from compilation using a define. Display can be ingame or be written to console. Currently shown are the number of calls, time sum, time avg, time min and time max of specified codeblocks. Profile data can be split in groups.

Some remarks: I tested and used it already somewhat, but it's not guaranteed to be bugfree. I hacked it down quite fast because i needed it urgently. It's using the standard library and not irrlicht base classes (simply because i'm more used to that). It's also not using the usual Irrlicht coding guidelines, as i'm using a different style in my project. Whoever wan'ts to fix or improve that - you're welcome ;)

Usage:
In Profiler.h there is a define to enable/disable the compilation of the macros.
Disable compilation by setting it to:

Code: Select all

#define IRR_PROFILE 0
The profiler needs the irrlicht timer, so you have to set this before using it. If you don't it will crash (sorry). You can do it like that in your code:

Code: Select all

#if IRR_PROFILE
    gPROFILER.SetTimer(irrlichtDevice->getTimer());
#endif // IRR_PROFILE
To add profile data you will need 4 defines:

Code: Select all

// Each group has only to be added once. Adding it again will overwrite the old group.
// groupId_: a custom group id - 0 is reserved but can be used nevertheless
// name_: will be used in display
PROFILE_ADD_GROUP(groupId_, name_)

// Each block has only to be added once. Adding it again will overwrite the old block.
// id: any custom id which you have to use in PROFILE_START and PROFILE_STOP
// groupId_: to put the this profile data in a specific group (for better layout)
// name_: used in display
PROFILE_ADD(id_, groupId_, name_)

// Start and stop  profiling blocks. Put this in your code wherever you like.
PROFILE_START(id_)
PROFILE_STOP(id_)
To control the profiler in game i catched some key down events like follows, but it's up to you how to do that in your own application:

Code: Select all

#if IRR_PROFILE
    case KEY_KEY_P:
    {
        gPROFILER.Print();
        gPROFILER.ResetAll();
        break;
    }
    case KEY_KEY_0:
    {
        gPROFILER.Hide( environment );
        break;
    };
    case KEY_KEY_1:
    {
        gPROFILER.Show(  environment );
        break;
    };
    case KEY_KEY_2:
    {
        gPROFILER.FirstDisplayGroup();
        gPROFILER.Show( environment );
        break;
    };
    case KEY_KEY_3:
    {
        gPROFILER.NextDisplayGroup();
        gPROFILER.Show( environment );
        break;
    };
    case KEY_KEY_4:
    {
        gPROFILER.PreviousDisplayGroup();
        gPROFILER.Show( environment );
        break;
    };
#endif // IRR_PROFILE
And here's the code:

profiler.h

Code: Select all

#ifndef PROFILER_H
#define PROFILER_H

// enable/disable compiling of profiler macros
#define IRR_PROFILE 1
#define PROFILER_GUI_ID 99999


#include <irrlicht.h>
#include <map>
#include <string>

namespace irr
{

struct ProfileData
{
    ProfileData();
    void Reset();

    u32 mGroupId;
    std::string mName;

    u32 mCountCalls;
    u32 mHighestTime;
    u32 mLowestTime;
    u32 mTimeSum;

    u32 mLastTimeStarted;
};

class Profiler
{
public:
    Profiler();
    virtual ~Profiler();

    void SetTimer(irr::ITimer * irrlichtTimer_)         { mIrrTimer = irrlichtTimer_; }

    // set the rectangle used for the display listbox
    void SetDisplayRect(const core::rect<s32> &rect_)   { mDisplayRect = rect_; }

    void Add(u32 id_, u32 groupId_, const std::string &name_);
    void AddGroup(u32 groupId_, const std::string &name_);
    void Start(u32 id_);
    void Stop(u32 id_);

    void Reset(u32 id_);
    void ResetGroup(u32 groupId_);
    void ResetAll();
    void Show(irr::gui::IGUIEnvironment* env_);        // print current display group on screen
    void Hide(irr::gui::IGUIEnvironment* env_);
    void Print();       // write current display group to wcout
    void PrintAll();    // write all groups to wcout

    void SetDisplayGroup(u32 groupId_);
    void NextDisplayGroup();
    void PreviousDisplayGroup();
    void FirstDisplayGroup();

protected:
    void PrintGroup(u32 groupId_);
    virtual std::string MakeDataString(const ProfileData & data_);
    virtual std::string MakeTitleString();

private:
    irr::ITimer * mIrrTimer;

    core::rect<s32> mDisplayRect;
    u32 mCurrentGroupId;
//    typedef ProfileDataMap std::map<u32, ProfileData>;
    std::map<u32, ProfileData>   mProfileDatas;
    std::map<u32, ProfileData>   mProfileGroups;
};

#if IRR_PROFILE
    extern Profiler gPROFILER;

    #define PROFILE_ADD(id_, groupId_, name_)   gPROFILER.Add(id_, groupId_, name_)
    #define PROFILE_ADD_GROUP(groupId_, name_)  gPROFILER.AddGroup(groupId_, name_)
    #define PROFILE_START(id_)                  gPROFILER.Start(id_)
    #define PROFILE_STOP(id_)                   gPROFILER.Stop(id_)
#else
    #define PROFILE_ADD(id_, groupId_, name_)
    #define PROFILE_ADD_GROUP(groupId_, name_)
    #define PROFILE_START(id_)
    #define PROFILE_STOP(id_)
#endif // IRR_PROFILE

} // namespace irr

#endif // PROFILER_H
profiler.cpp

Code: Select all

#include <iostream>
#include <sstream>
#include <iomanip>
#include <limits.h>
#include "profiler.h"

using namespace irr;

#if IRR_PROFILE
Profiler irr::gPROFILER;
#endif // IRR_PROFILE

ProfileData::ProfileData()
{
    mGroupId = 0;
    Reset();
}

void ProfileData::Reset()
{
    mCountCalls = 0;
    mHighestTime = 0;
    mLowestTime = UINT_MAX;
    mTimeSum = 0;
    mLastTimeStarted = 0;
}

Profiler::Profiler()
:  mDisplayRect(0, 40, 600, 400)
{
    mCurrentGroupId = 0;
    AddGroup(0, "overview");
    mProfileGroups[0].mGroupId = UINT_MAX;
}

Profiler::~Profiler()
{
}

void Profiler::Add(u32 id_, u32 groupId_, const std::string &name_)
{
    ProfileData &data = mProfileDatas[id_];
    data.Reset();
    data.mName = name_;
    data.mGroupId = groupId_;
}

void Profiler::AddGroup(u32 groupId_, const std::string &name_)
{
    ProfileData group;
    group.mName = name_;
    mProfileGroups[groupId_] = group;
}

void Profiler::Reset(u32 id_)
{
    std::map<u32, ProfileData>::iterator itData = mProfileDatas.find(id_);
    if ( itData != mProfileDatas.end() )
    {
        std::map<u32, ProfileData>::iterator itGroup = mProfileGroups.find(itData->second.mGroupId);
        if ( itGroup != mProfileGroups.end() )
        {
            itGroup->second.mCountCalls -= itData->second.mCountCalls;
            itGroup->second.mTimeSum -= itData->second.mTimeSum;
        }

        itData->second.Reset();
    }
}

void Profiler::ResetGroup(u32 groupId_)
{
    std::map<u32, ProfileData>::iterator itData = mProfileDatas.begin();
    for ( ; itData != mProfileDatas.end(); ++itData )
    {
        if ( itData->second.mGroupId == groupId_ )
        {
            Reset(itData->first);
        }
    }
}

void Profiler::Start(u32 id_)
{
    mProfileDatas[id_].mLastTimeStarted = mIrrTimer->getRealTime();
}

void Profiler::Stop(u32 id_)
{
    ProfileData &data = mProfileDatas[id_];
    u32 diffTime = mIrrTimer->getRealTime() - data.mLastTimeStarted;
    if ( data.mLastTimeStarted == 0 )
        return;

    ++data.mCountCalls;
    data.mTimeSum += diffTime;
    if ( diffTime > data.mHighestTime )
        data.mHighestTime = diffTime;
    if ( diffTime < data.mLowestTime )
        data.mLowestTime = diffTime;
    data.mLastTimeStarted = 0;

    ProfileData & group = mProfileGroups[data.mGroupId];
    ++group.mCountCalls;
    group.mTimeSum += diffTime;
    if ( diffTime > group.mHighestTime )
        group.mHighestTime = diffTime;
    if ( diffTime < group.mLowestTime )
        group.mLowestTime = diffTime;
    group.mLastTimeStarted = 0;
}

void Profiler::ResetAll()
{
    std::map<u32, ProfileData>::iterator itData = mProfileDatas.begin();
    for ( ; itData != mProfileDatas.end(); ++itData )
    {
        itData->second.Reset();
    }

    std::map<u32, ProfileData>::iterator itGroup = mProfileGroups.begin();
    for ( ; itGroup != mProfileGroups.end(); ++itGroup )
    {
        itGroup->second.Reset();
    }
}

void Profiler::Show(irr::gui::IGUIEnvironment* env_)
{
    if ( !env_)
        return;

    Hide(env_);

	gui::IGUIListBox* listBox = env_->addListBox(mDisplayRect, 0, PROFILER_GUI_ID, true);

    std::string strTitle(MakeTitleString());
    std::wstring wstrTitle(strTitle.begin(), strTitle.end());
    listBox->addItem(wstrTitle.c_str());

    std::map<u32, ProfileData>::iterator itGroup = mProfileGroups.find(mCurrentGroupId);
    if ( itGroup == mProfileGroups.end() )
        return;

    std::string strGroup(MakeDataString(itGroup->second));
    std::wstring wstrGroup(strGroup.begin(), strGroup.end());
    listBox->addItem(wstrGroup.c_str());

    if ( mCurrentGroupId == 0 )
    {
        std::map<u32, ProfileData>::iterator itData = mProfileGroups.begin();
        for ( ; itData != mProfileGroups.end(); ++itData )
        {
            if ( itData->second.mGroupId == mCurrentGroupId )
            {
                std::string strData(MakeDataString(itData->second));
                std::wstring wstrData(strData.begin(), strData.end());
                listBox->addItem(wstrData.c_str());
            }
        }
    }
    else
    {
        std::map<u32, ProfileData>::iterator itData = mProfileDatas.begin();
        for ( ; itData != mProfileDatas.end(); ++itData )
        {
            if ( itData->second.mGroupId == mCurrentGroupId )
            {
                std::string strData(MakeDataString(itData->second));
                std::wstring wstrData(strData.begin(), strData.end());
                listBox->addItem(wstrData.c_str());
            }
        }
    }
}

void Profiler::Hide(irr::gui::IGUIEnvironment* env_)
{
    if ( !env_)
        return;

	gui::IGUIElement* root = env_->getRootGUIElement();
	gui::IGUIElement* e = root->getElementFromId(PROFILER_GUI_ID, true);
	if (e)
	{
        e->remove();
	}
}

void Profiler::SetDisplayGroup(u32 groupId_)
{
    mCurrentGroupId = groupId_;
}

void Profiler::NextDisplayGroup()
{
    std::map<u32, ProfileData>::iterator itGroup = mProfileGroups.find(mCurrentGroupId);
    if ( itGroup == mProfileGroups.end() )
    {
        mCurrentGroupId = 0;
    }
    else
    {
        ++itGroup;
        if ( itGroup == mProfileGroups.end() )
            itGroup = mProfileGroups.begin();
        mCurrentGroupId  = itGroup->first;
    }
}

void Profiler::PreviousDisplayGroup()
{
    std::map<u32, ProfileData>::iterator itGroup = mProfileGroups.find(mCurrentGroupId);
    if ( itGroup == mProfileGroups.end() )
    {
        mCurrentGroupId = 0;
    }
    else
    {
        if ( itGroup == mProfileGroups.begin() )
        {
            itGroup = mProfileGroups.end();
        }
        --itGroup;
        mCurrentGroupId  = itGroup->first;
    }
}

void Profiler::FirstDisplayGroup()
{
    std::map<u32, ProfileData>::iterator itGroup = mProfileGroups.begin();
    if ( itGroup == mProfileGroups.end() )
    {
        mCurrentGroupId = 0;
    }
    else
    {
        mCurrentGroupId = itGroup->first;
    }
}

void Profiler::Print()
{
    std::cout << MakeTitleString();
    PrintGroup(mCurrentGroupId);
}

void Profiler::PrintAll()
{
    std::cout << MakeTitleString();
    std::map<u32, ProfileData>::iterator itGroup = mProfileGroups.begin();
    for ( ; itGroup != mProfileGroups.end(); ++itGroup )
    {
        PrintGroup( itGroup->first );
    }
}

void Profiler::PrintGroup(u32 groupId_)
{
    std::map<u32, ProfileData>::iterator itGroup = mProfileGroups.find(groupId_);
    if ( itGroup == mProfileGroups.end() )
        return;

    std::cout << MakeDataString(itGroup->second);

    if ( groupId_ == 0 )
    {
        std::map<u32, ProfileData>::iterator itData = mProfileGroups.begin();
        for ( ; itData != mProfileGroups.end(); ++itData )
        {
            if ( itData->second.mGroupId == groupId_ )
            {
                std::cout << MakeDataString(itData->second);
            }
        }
    }
    else
    {
        std::map<u32, ProfileData>::iterator itData = mProfileDatas.begin();
        for ( ; itData != mProfileDatas.end(); ++itData )
        {
            if ( itData->second.mGroupId == groupId_ )
            {
                std::cout << MakeDataString(itData->second);
            }
        }
    }
}

std::string Profiler::MakeTitleString()
{
    std::ostringstream ostr;
    ostr << "name           calls       time(sum)   time(avg)   time(max)   time(min)   " << std::endl;

    return ostr.str();
}

std::string Profiler::MakeDataString(const ProfileData & data_)
{
    std::ostringstream ostr;

    if ( data_.mCountCalls > 0 )
    {
        ostr << std::left << std::setw(15) << data_.mName << std::setw(12) << data_.mCountCalls
            << std::setw(12) << data_.mTimeSum
            << std::setw(12) << data_.mTimeSum / data_.mCountCalls
            << std::setw(12) << data_.mHighestTime
            << std::setw(12) << (data_.mLowestTime < data_.mHighestTime ? data_.mLowestTime : 0)
            << std::endl;
    }
    else
    {
        ostr << data_.mName << std::endl;
    }

    return ostr.str();
}
Any feedback is welcome ;)

Edit (2006/05/04): I removed the widechar-streams, because MinGW doesn't support it yet.
Vectrotek
Competition winner
Posts: 1087
Joined: Sat May 02, 2015 5:05 pm

Re: (C++) Simple speed profiler

Post by Vectrotek »

Thanks! I could use this..
CuteAlien
Admin
Posts: 9628
Joined: Mon Mar 06, 2006 2:25 pm
Location: Tübingen, Germany
Contact:

Re: (C++) Simple speed profiler

Post by CuteAlien »

Note that if you use Irrlicht svn trunk then a similar profiler is included now.
IRC: #irrlicht on irc.libera.chat
Code snippet repository: https://github.com/mzeilfelder/irr-playground-micha
Free racer made with Irrlicht: http://www.irrgheist.com/hcraftsource.htm
Post Reply