Boost logo

Boost :

From: Andrew Schweitzer (a.schweitzer.grps_at_[hidden])
Date: 2005-11-15 10:28:28


Code is attached.
These were built by with vc7.1 by creating a console project, adding
these files, adding links to the boost libs, including boost_root.

It should build for you. Please post if you try and have problems.

After printing 20,000 numbers to the console it should have output like:
release
|Tk:|1282| Th:|155| NS/call:|15625| cout|
|Tk:|1281| Th:|343| NS/call:|34375| enabled log|
|Tk:|0| Th:|0| NS/call:|0| cout disabled|
|Tk:|16| Th:|15| NS/call:|15| disabled log|

Basically works like this:
        
        string l_sDC;
        disable_logs("lgTest");

        START_MEASUREQ(1000000, "disabled log", &l_sDL)
        
                BOOST_SCOPEDLOG(l_lgTest) << l_ui << endl;

        STOP_MEASURE()
        
        BOOST_SCOPEDLOG(l_lg)
                << l_sDL << endl;

There's a supporting cMeasureTime class that records time.
Macros basically start and stop a for loop, then record the results to a
string (or log if you pass in a logger).

> _______________________________________________
> Unsubscribe & other changes: http://lists.boost.org/mailman/listinfo.cgi/boost
>


bool UseCout(){return false;}

#include "windows.h"
#include "boost/log/log.hpp"
#include <boost/log/functions.hpp>
#include <boost/format.hpp>

#include <iostream>
using namespace std;

using namespace boost::logging;
using namespace boost;

class cMeasureTime
{
public:
        cMeasureTime(){memset(this, 0, sizeof(*this));}
        void Start()
        {
                m_uiStartTick = GetTickCount();
                FILETIME l_CreationTime;
                FILETIME l_ExitTime;

                if(!GetThreadTimes(GetCurrentThread(),
                                           &l_CreationTime,
                                           &l_ExitTime,
                                           (FILETIME*)&m_ui64KStart,
                                           (FILETIME*)&m_ui64UStart))
                {
                        cout << "GetThreadTimes failed: " << GetLastError() << endl;
                }
        }

        void Stop()
        {
                ++m_uiCalls;
                DWORD l_dwEndTick = GetTickCount();
                m_uiTickDiff =
                        l_dwEndTick > m_uiStartTick ?
                                l_dwEndTick - m_uiStartTick :
                                m_uiStartTick - l_dwEndTick;
                m_uiTickDiffTotal += m_uiTickDiff;

                FILETIME l_CreationTime;
                FILETIME l_ExitTime;
                unsigned __int64 l_ui64KEnd, l_ui64UEnd;
                if(!GetThreadTimes(GetCurrentThread(),
                                           &l_CreationTime,
                                           &l_ExitTime,
                                           (FILETIME*)&l_ui64KEnd,
                                           (FILETIME*)&l_ui64UEnd))
                {
                        cout << "GetThreadTimes failed: " << GetLastError() << endl;
                }

                m_ui64KDiff = l_ui64KEnd - m_ui64KStart;
                m_ui64UDiff = l_ui64UEnd - m_ui64UStart;
                m_ui64KDiffTotal += m_ui64KDiff;
                m_ui64UDiffTotal += m_ui64UDiff;
        }
        
        unsigned int GetCalls() const {return m_uiCalls;}
        unsigned __int64 GetTickDiffMS() const {return m_uiTickDiff;}
        unsigned __int64 GetKDiffHNS() const {return m_ui64KDiff;}
        unsigned __int64 GetUDiffHNS() const {return m_ui64UDiff;}
        unsigned __int64 GetThDiffHNS() const {return GetKDiffHNS() + GetUDiffHNS();}
        unsigned __int64 GetKDiffMS() const {return GetKDiffHNS() / 10000;}
        unsigned __int64 GetUDiffMS() const {return GetUDiffHNS() / 10000;}
        unsigned __int64 GetThDiffMS() const {return GetKDiffMS() + GetUDiffMS();}

        unsigned int GetTickDiffTotalMS()const {return m_uiTickDiffTotal;}
        unsigned __int64 GetKDiffTotalHNS() const {return m_ui64KDiffTotal;}
        unsigned __int64 GetUDiffTotalHNS() const {return m_ui64UDiffTotal;}
        unsigned __int64 GetThDiffTotalHNS() const {return GetKDiffTotalHNS() + GetUDiffTotalHNS();}
        unsigned __int64 GetKDiffTotalMS() const {return GetUDiffTotalHNS() / 1000;}
        unsigned __int64 GetUDiffTotalMS() const {return GetKDiffTotalHNS() / 1000;}
        unsigned __int64 GetThDiffTotalMS() const {return GetKDiffTotalMS() + GetUDiffTotalMS();}
        
        unsigned __int64 GetThNSperCall(unsigned int uiItr) const
        {
                unsigned __int64 l_ui64ThNS = GetThDiffHNS() * 100;
                unsigned __int64 l_uiNSperCall = 0;
                if(uiItr)
                {
                        l_uiNSperCall = l_ui64ThNS / uiItr;
                }
                return l_uiNSperCall;
        }

        unsigned __int64 GetThNSperCallTotal() const
        {
                unsigned __int64 l_ui64ThNS = GetThDiffTotalHNS() * 100;
                unsigned __int64 l_uiNSperCall = 0;
                if(m_uiCalls)
                {
                        l_uiNSperCall = l_ui64ThNS / m_uiCalls;
                }
                return l_uiNSperCall;
        }

        string ShortString(unsigned int uiItr, string strTag = "") const
        {
                format l_fmt("|Tk:|%u| Th:|%u| NS/call:|%u| %s|");
                l_fmt % GetTickDiffMS() % GetThDiffMS() % GetThNSperCall(uiItr) % strTag;
                return l_fmt.str();
        }

        string ShortStringTotal(string strTag = "") const
        {
                format l_fmt("|Tk:|%u| Th:|%u| NS/call:|%u| %s|");
                l_fmt % GetTickDiffMS() % GetThDiffMS() % GetThNSperCallTotal() % strTag;
                return l_fmt.str();
        }

private:
        unsigned int m_uiCalls;
        unsigned int m_uiTickDiff;
        unsigned __int64 m_ui64KDiff;
        unsigned __int64 m_ui64UDiff;

        unsigned int m_uiTickDiffTotal;
        unsigned __int64 m_ui64KDiffTotal;
        unsigned __int64 m_ui64UDiffTotal;

        unsigned int m_uiStartTick;
        unsigned __int64 m_ui64KStart;
        unsigned __int64 m_ui64UStart;
};

#define START_MEASURE(uiItr_, szTag_, pLog_, pMeasureTime_, pString_) \
{ \
        unsigned int l_uiItr = uiItr_; \
        const char* l_szTag = szTag_; \
        logger* l_pLog = pLog_; \
        cMeasureTime* l_pMT = pMeasureTime_; \
        cMeasureTime l_MT; \
        if(!l_pMT){l_pMT = &l_MT;} \
        string* l_pString = pString_; \
        l_pMT->Start(); \
        for(unsigned int l_ui = 0; l_ui < l_uiItr; ++l_ui) \
        { \

#define STOP_MEASURE() \
        } \
        l_pMT->Stop(); \
        if(l_pString) \
        { \
                *l_pString = l_pMT->ShortString(l_uiItr, l_szTag); \
        } \
        if(l_pLog) \
        { \
                BOOST_SCOPEDLOG(*l_pLog) << l_pMT->ShortString(l_uiItr, l_szTag); \
        } \
} \

#define START_MEASUREQ(uiItr_, szTag_, pString_) \
                        START_MEASURE(uiItr_, szTag_, NULL, NULL, pString_)

extern bool UseCout();

int main(int argc, char* argv[])
{
        logger l_lg("lg");
        logger l_lgTest("lgTest");
        manipulate_logs("*").add_appender(write_to_cout);
        enable_logs("lg");
        set_log_caching(false);
                
        string l_sCout, l_sDL, l_sEL, l_sDC;

        START_MEASUREQ(10000, "cout", &l_sCout)

                cout << l_ui << endl;

        STOP_MEASURE()
        
        START_MEASUREQ(1000000, "cout disabled", &l_sDC)

        if(UseCout())
        {
                cout << l_ui << endl;
        }

        STOP_MEASURE()

        disable_logs("lgTest");

        START_MEASUREQ(1000000, "disabled log", &l_sDL)

                BOOST_SCOPEDLOG(l_lgTest) << l_ui << endl;

        STOP_MEASURE()

        enable_logs("lgTest");

        START_MEASUREQ(10000, "enabled log", &l_sEL)

                BOOST_SCOPEDLOG(l_lgTest) << l_ui << endl;

        STOP_MEASURE()

#ifdef _DEBUG
        BOOST_SCOPEDLOG(l_lg) << "debug" << endl;
#else
        BOOST_SCOPEDLOG(l_lg) << "release" << endl;
#endif
        BOOST_SCOPEDLOG(l_lg)
                << l_sCout << endl;
        BOOST_SCOPEDLOG(l_lg)
                << l_sEL << endl;
        BOOST_SCOPEDLOG(l_lg)
                << l_sDC << endl;
        BOOST_SCOPEDLOG(l_lg)
                << l_sDL << endl;

        return 0;
}


Boost list run by bdawes at acm.org, gregod at cs.rpi.edu, cpdaniel at pacbell.net, john at johnmaddock.co.uk